10 Replies Latest reply on Mar 22, 2007 7:10 PM by Kevin Conner

    Jboss 4.2.0CR1 - "Unabled to enlist resource" problem

    olivier merlin Newbie

      Hello,

      We have really a blocking problem with JTA / Hibernate JDBC Transaction.
      We are doing in a SSB a simple findByXXX method and we get systematically a javax.transaction.SystemException : Unabled to enlist resource

      Context & problem analysis
      -----------------------------------
      * We checked several time the datasource - the message at the head of the stack " Cannot open connection [???]" is not related to a database problem
      * In the same servlet session & context - we did previously some findByXXX calls that use the same datasource
      * We only do SELECT jdbc call in the servlet session
      * To help analysis we activate the full trace on ARJUNA

      Hypothesis
      --------------
      We suspect an Hibernate EntityManager side effect in the transaction

      NOTE : in the trace you can see a JDBC transaction that was successfully enlisted by the Transaction Manager and then the failling transaction

      TRACE
      ----------
      2007-03-20 13:50:11,941 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@468fa3 )
      2007-03-20 13:50:11,941 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:11,942 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 0:0:0:1 )
      2007-03-20 13:50:11,942 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (0:0:0:1)
      2007-03-20 13:50:11,942 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord()
      2007-03-20 13:50:11,942 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/LastResourceRecord for 0:0:0:1
      2007-03-20 13:50:11,944 DEBUG [org.hibernate.SQL] select operatione0_.ID as ID0_, operatione0_.TIMESTAMP as TIMESTAMP0_, operatione0_.MSISDN as MSISDN0_, operatione0_.ICCID as ICCID0_, operatione0_.COMMAND_NAME as COMMAND5_0_, operatione0_.COMMAND_PARAMETERS as COMMAND6_0_, operatione0_.PRODUCT_TYPE as PRODUCT7_0_, operatione0_.MONITORING_ID as MONITORING8_0_, operatione0_.REQUESTER as REQUESTER0_, operatione0_.RESULT_CODE as RESULT10_0_, operatione0_.RESULT_DETAIL as RESULT11_0_, operatione0_.TERMINATED as TERMINATED0_ from OCP_HISTORY operatione0_ where operatione0_.ICCID=? and operatione0_.TERMINATED='F' order by operatione0_.TIMESTAMP
      2007-03-20 13:50:11,944 INFO [STDOUT] Hibernate: select operatione0_.ID as ID0_, operatione0_.TIMESTAMP as TIMESTAMP0_, operatione0_.MSISDN as MSISDN0_, operatione0_.ICCID as ICCID0_, operatione0_.COMMAND_NAME as COMMAND5_0_, operatione0_.COMMAND_PARAMETERS as COMMAND6_0_, operatione0_.PRODUCT_TYPE as PRODUCT7_0_, operatione0_.MONITORING_ID as MONITORING8_0_, operatione0_.REQUESTER as REQUESTER0_, operatione0_.RESULT_CODE as RESULT10_0_, operatione0_.RESULT_DETAIL as RESULT11_0_, operatione0_.TERMINATED as TERMINATED0_ from OCP_HISTORY operatione0_ where operatione0_.ICCID=? and operatione0_.TERMINATED='F' order by operatione0_.TIMESTAMP
      2007-03-20 13:50:12,142 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
      2007-03-20 13:50:12,144 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
      2007-03-20 13:50:12,144 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
      2007-03-20 13:50:12,144 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
      2007-03-20 13:50:12,144 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
      2007-03-20 13:50:12,144 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,144 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,146 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
      2007-03-20 13:50:12,146 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,147 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,154 INFO [com.gemalto.mmserver.infra.services.impl.JobControllerBean] No job in process for the iccid : 200000004
      2007-03-20 13:50:12,155 INFO [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Job completed :true
      2007-03-20 13:50:12,155 INFO [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Getting next business command
      2007-03-20 13:50:12,155 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Called : JobControllerBean.lookForNextBusinessCommand
      2007-03-20 13:50:12,155 INFO [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Product type not yet defined
      2007-03-20 13:50:12,155 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Called : JobControllerBean.getNextProduct
      2007-03-20 13:50:12,155 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Called : JobControllerBean.getNextProductType
      2007-03-20 13:50:12,155 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Called : JobControllerBean.getProductTypeList
      2007-03-20 13:50:12,156 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.suspend
      2007-03-20 13:50:12,156 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:49 removing TSThread:4
      2007-03-20 13:50:12,156 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:49 removing TSThread:4 result = true
      2007-03-20 13:50:12,156 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.begin
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 2 )
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::BasicAction()
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::Begin() for action-id a0aa44a:cf61:45ffd85c:51
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::actionInitialise() for action-id a0aa44a:cf61:45ffd85c:51
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::ActionHierarchy(5)
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::add(a0aa44a:cf61:45ffd85c:51, 1)
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:51 adding Thread[ajp-0.0.0.0-8010-1,5,jboss]
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:51 adding Thread[ajp-0.0.0.0-8010-1,5,jboss] result = true
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::insert ( BasicAction: a0aa44a:cf61:45ffd85c:51 status: ActionStatus.RUNNING, 300 )
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement::ReaperElement ( BasicAction: a0aa44a:cf61:45ffd85c:51 status: ActionStatus.RUNNING, 300 )
      2007-03-20 13:50:12,157 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement.greaterThan ()
      2007-03-20 13:50:12,174 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1fbaf73 )
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 0:0:0:1 )
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (0:0:0:1)
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord()
      2007-03-20 13:50:12,175 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/LastResourceRecord for 0:0:0:1
      2007-03-20 13:50:12,178 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,178 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.commit
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.commitAndDisassociate
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::End() for action-id a0aa44a:cf61:45ffd85c:51
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::onePhaseCommit() for action-id a0aa44a:cf61:45ffd85c:51
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord::topLevelPrepare() for 0:0:0:1
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord::topLevelCommit() for 0:0:0:1
      2007-03-20 13:50:12,182 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,183 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,183 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:51 removing TSThread:4
      2007-03-20 13:50:12,183 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:51 removing TSThread:4 result = true
      2007-03-20 13:50:12,183 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
      2007-03-20 13:50:12,183 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::remove ( BasicAction: a0aa44a:cf61:45ffd85c:51 status: ActionStatus.COMMITTED )
      2007-03-20 13:50:12,183 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.resume
      2007-03-20 13:50:12,183 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:49 adding Thread[ajp-0.0.0.0-8010-1,5,jboss]
      2007-03-20 13:50:12,183 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:49 adding Thread[ajp-0.0.0.0-8010-1,5,jboss] result = true
      2007-03-20 13:50:12,183 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Product list : [OCP]
      2007-03-20 13:50:12,183 INFO [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Get next product type :OCP
      2007-03-20 13:50:12,183 INFO [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Next product type :OCP
      2007-03-20 13:50:12,183 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Called : JobControllerBean.getProduct
      2007-03-20 13:50:12,183 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Called : JobControllerBean.getProductName
      2007-03-20 13:50:12,184 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Called : JobControllerBean.getProductsAccessType
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.suspend
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:49 removing TSThread:4
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:49 removing TSThread:4 result = true
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.begin
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 2 )
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::BasicAction()
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::Begin() for action-id a0aa44a:cf61:45ffd85c:55
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::actionInitialise() for action-id a0aa44a:cf61:45ffd85c:55
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::ActionHierarchy(5)
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::add(a0aa44a:cf61:45ffd85c:55, 1)
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:55 adding Thread[ajp-0.0.0.0-8010-1,5,jboss]
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:55 adding Thread[ajp-0.0.0.0-8010-1,5,jboss] result = true
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::insert ( BasicAction: a0aa44a:cf61:45ffd85c:55 status: ActionStatus.RUNNING, 300 )
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement::ReaperElement ( BasicAction: a0aa44a:cf61:45ffd85c:55 status: ActionStatus.RUNNING, 300 )
      2007-03-20 13:50:12,184 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement.greaterThan ()
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement.greaterThan ()
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1fbaf73 )
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 0:0:0:1 )
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (0:0:0:1)
      2007-03-20 13:50:12,185 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord()
      2007-03-20 13:50:12,186 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/LastResourceRecord for 0:0:0:1
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.commit
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.commitAndDisassociate
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::End() for action-id a0aa44a:cf61:45ffd85c:55
      2007-03-20 13:50:12,187 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::onePhaseCommit() for action-id a0aa44a:cf61:45ffd85c:55
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord::topLevelPrepare() for 0:0:0:1
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord::topLevelCommit() for 0:0:0:1
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:55 removing TSThread:4
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:55 removing TSThread:4 result = true
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::remove ( BasicAction: a0aa44a:cf61:45ffd85c:55 status: ActionStatus.COMMITTED )
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.resume
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:49 adding Thread[ajp-0.0.0.0-8010-1,5,jboss]
      2007-03-20 13:50:12,188 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:49 adding Thread[ajp-0.0.0.0-8010-1,5,jboss] result = true
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.suspend
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:49 removing TSThread:4
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:49 removing TSThread:4 result = true
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.begin
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 2 )
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::BasicAction()
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::Begin() for action-id a0aa44a:cf61:45ffd85c:59
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::actionInitialise() for action-id a0aa44a:cf61:45ffd85c:59
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::ActionHierarchy(5)
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ActionHierarchy::add(a0aa44a:cf61:45ffd85c:59, 1)
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:59 adding Thread[ajp-0.0.0.0-8010-1,5,jboss]
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:59 adding Thread[ajp-0.0.0.0-8010-1,5,jboss] result = true
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::insert ( BasicAction: a0aa44a:cf61:45ffd85c:59 status: ActionStatus.RUNNING, 300 )
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement::ReaperElement ( BasicAction: a0aa44a:cf61:45ffd85c:59 status: ActionStatus.RUNNING, 300 )
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement.greaterThan ()
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement.greaterThan ()
      2007-03-20 13:50:12,189 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] ReaperElement.greaterThan ()
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1fbaf73 )
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 0:0:0:1 )
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (0:0:0:1)
      2007-03-20 13:50:12,190 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord()
      2007-03-20 13:50:12,191 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.RecordList_5] - RecordList::insert(RecordList: empty) : appending /StateManager/AbstractRecord/LastResourceRecord for 0:0:0:1
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.commit
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.commitAndDisassociate
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.beforeCompletion
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::End() for action-id a0aa44a:cf61:45ffd85c:59
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::onePhaseCommit() for action-id a0aa44a:cf61:45ffd85c:59
      2007-03-20 13:50:12,192 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord::topLevelPrepare() for 0:0:0:1
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord::topLevelCommit() for 0:0:0:1
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_8] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:59 removing TSThread:4
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_9] - BasicAction::removeChildThread () action a0aa44a:cf61:45ffd85c:59 removing TSThread:4 result = true
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::create ( 120000 )
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] TransactionReaper::remove ( BasicAction: a0aa44a:cf61:45ffd85c:59 status: ActionStatus.COMMITTED )
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImpleManager.resume
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_6] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:49 adding Thread[ajp-0.0.0.0-8010-1,5,jboss]
      2007-03-20 13:50:12,193 DEBUG [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_7] - BasicAction::addChildThread () action a0aa44a:cf61:45ffd85c:49 adding Thread[ajp-0.0.0.0-8010-1,5,jboss] result = true
      2007-03-20 13:50:12,194 INFO [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Calling getNextBusinessCommand on OCP
      2007-03-20 13:50:12,194 DEBUG [com.gemalto.mmserver.infra.services.impl.JobControllerBean] Called : JobControllerBean.getNextBusinessCommand
      2007-03-20 13:50:12,201 DEBUG [com.gemalto.mmserver.ocp.interceptors.impl.MethodInterceptor] Method [17750771] OcpBusinessCommandControllerSpiBean.getNextBusinessCommand() called with 2 parameters
      2007-03-20 13:50:12,201 DEBUG [com.gemalto.mmserver.ocp.interceptors.impl.MethodInterceptor] Method [17750771] parameter #0 type = String; value = 200000004
      2007-03-20 13:50:12,201 DEBUG [com.gemalto.mmserver.ocp.interceptors.impl.MethodInterceptor] Method [17750771] parameter #1 type = CardCommunicationContext; value = [CardCommunicationContext [productType:OCP][jobId:-1][httpRequestSetId:null][currentUrl:http://signes:1793/CEH/cehocp][fragmentPolicyId:null][monitoringEnabled:true][requester:null][queryParameters:]]
      2007-03-20 13:50:12,205 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,205 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,205 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4810321969991680
      2007-03-20 13:50:12,205 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
      2007-03-20 13:50:12,205 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,205 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,205 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,205 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,205 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,205 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,205 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.registerSynchronization
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
      2007-03-20 13:50:12,206 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] Transaction already joined
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
      2007-03-20 13:50:12,206 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.enlistResource ( org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@185477d )
      2007-03-20 13:50:12,206 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,207 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StateManager::StateManager( 0:0:0:1 )
      2007-03-20 13:50:12,207 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AbstractRecord::AbstractRecord (0:0:0:1)
      2007-03-20 13:50:12,207 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord()
      2007-03-20 13:50:12,210 DEBUG [org.hibernate.util.JDBCExceptionReporter] Cannot open connection [???]
      org.jboss.util.NestedSQLException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: a0aa44a:cf61:45ffd85c:49 status: ActionStatus.ABORT_ONLY >); - nested throwable: (org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: a0aa44a:cf61:45ffd85c:49 status: ActionStatus.ABORT_ONLY >))
      at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:94)
      at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:47)
      at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
      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:1538)
      at org.hibernate.loader.Loader.doQuery(Loader.java:661)
      at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
      at org.hibernate.loader.Loader.doList(Loader.java:2211)
      at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2095)
      at org.hibernate.loader.Loader.list(Loader.java:2090)
      at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:388)
      at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
      at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
      at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
      at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
      at org.hibernate.ejb.QueryImpl.getSingleResult(QueryImpl.java:80)
      at com.gemalto.mmserver.ocp.services.impl.subscriptions.CardPersistenceServiceBean.findCardByIccid(CardPersistenceServiceBean.java:274)
      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:585)
      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.invokeInCallerTx(TxPolicy.java:126)
      at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
      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:105)
      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:274)
      at org.jboss.ejb3.remoting.IsLocalInterceptor.invoke(IsLocalInterceptor.java:65)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.stateless.StatelessRemoteProxy.invoke(StatelessRemoteProxy.java:103)
      at $Proxy161.findCardByIccid(Unknown Source)
      at com.gemalto.mmserver.ocp.services.impl.otainfra.dispatcher.BusinessCommandDispatcherBean.getNextBusinessCommand(BusinessCommandDispatcherBean.java:82)
      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:585)
      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.invokeInCallerTx(TxPolicy.java:126)
      at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
      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:105)
      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.localInvoke(StatelessContainer.java:210)
      at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:180)
      at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:81)
      at $Proxy173.getNextBusinessCommand(Unknown Source)
      at com.gemalto.mmserver.ocp.services.impl.otainfra.spi.OcpBusinessCommandControllerSpiBean.getNextBusinessCommand(OcpBusinessCommandControllerSpiBean.java:79)
      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:585)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
      at com.gemalto.mmserver.ocp.interceptors.impl.ProfilingInterceptor.audit(ProfilingInterceptor.java:32)
      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:585)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118)
      at com.gemalto.mmserver.ocp.interceptors.impl.MethodInterceptor.traceCall(MethodInterceptor.java:52)
      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:585)
      at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118)
      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.invokeInCallerTx(TxPolicy.java:126)
      at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)
      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:105)
      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:274)
      at org.jboss.ejb3.remoting.IsLocalInterceptor.invoke(IsLocalInterceptor.java:65)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.stateless.StatelessRemoteProxy.invoke(StatelessRemoteProxy.java:103)
      at $Proxy176.getNextBusinessCommand(Unknown Source)
      at com.gemalto.mmserver.infra.services.impl.JobControllerBean.getNextBusinessCommand(JobControllerBean.java:410)
      at com.gemalto.mmserver.infra.services.impl.JobControllerBean.lookForNextBusinessCommand(JobControllerBean.java:795)
      at com.gemalto.mmserver.infra.services.impl.JobControllerBean.getNextHttpRequestSetDirective(JobControllerBean.java:224)
      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:585)
      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:76)
      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:105)
      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:274)
      at org.jboss.ejb3.remoting.IsLocalInterceptor.invoke(IsLocalInterceptor.java:65)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
      at org.jboss.ejb3.stateless.StatelessRemoteProxy.invoke(StatelessRemoteProxy.java:103)
      at $Proxy200.getNextHttpRequestSetDirective(Unknown Source)
      at com.gemalto.mmserver.infra.comm.servlet.CardEventHandlerServlet.getNextHttpRequestSetDirective(CardEventHandlerServlet.java:526)
      at com.gemalto.mmserver.infra.comm.servlet.CardEventHandlerServlet.doPost(CardEventHandlerServlet.java:793)
      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:228)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
      at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175)
      at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
      at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:156)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:216)
      at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:437)
      at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:447)
      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:445)
      at java.lang.Thread.run(Thread.java:595)
      Caused by: org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: a0aa44a:cf61:45ffd85c:49 status: ActionStatus.ABORT_ONLY >)
      at org.jboss.resource.connectionmanager.TxConnectionManager.managedConnectionReconnected(TxConnectionManager.java:343)
      at org.jboss.resource.connectionmanager.BaseConnectionManager2.reconnectManagedConnection(BaseConnectionManager2.java:518)
      at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:399)
      at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:842)
      at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
      ... 179 more
      Caused by: javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: a0aa44a:cf61:45ffd85c:49 status: ActionStatus.ABORT_ONLY >
      at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener$TransactionSynchronization.checkEnlisted(TxConnectionManager.java:744)
      at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener.enlist(TxConnectionManager.java:577)
      at org.jboss.resource.connectionmanager.TxConnectionManager.managedConnectionReconnected(TxConnectionManager.java:337)
      ... 183 more
      2007-03-20 13:50:12,215 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: null
      2007-03-20 13:50:12,215 ERROR [org.hibernate.util.JDBCExceptionReporter] Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: a0aa44a:cf61:45ffd85c:49 status: ActionStatus.ABORT_ONLY >); - nested throwable: (org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: a0aa44a:cf61:45ffd85c:49 status: ActionStatus.ABORT_ONLY >))
      2007-03-20 13:50:12,216 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,216 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,216 DEBUG [org.hibernate.ejb.AbstractEntityManagerImpl] mark transaction for rollback
      2007-03-20 13:50:12,217 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.setRollbackOnly
      2007-03-20 13:50:12,217 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
      2007-03-20 13:50:12,217 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
      2007-03-20 13:50:12,324 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
      2007-03-20 13:50:12,324 DEBUG [com.gemalto.mmserver.ocp.interceptors.impl.ProfilingInterceptor] Method OcpBusinessCommandControllerSpiBean.getNextBusinessCommand() took 123 ms
      2007-03-20 13:50:12,324 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
      2007-03-20 13:50:12,375 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.setRollbackOnly
      2007-03-20 13:50:12,375 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,375 DEBUG [com.arjuna.ats.jta.logging.logger] BaseTransaction.rollback
      2007-03-20 13:50:12,375 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.rollbackAndDisassociate
      2007-03-20 13:50:12,375 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::Abort() for action-id a0aa44a:cf61:45ffd85c:49
      2007-03-20 13:50:12,375 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] BasicAction::doAbort (com.arjuna.ats.arjuna.LastResourceRecord@302f39)
      2007-03-20 13:50:12,375 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] LastResourceRecord::topLevelAbort() for 0:0:0:1
      2007-03-20 13:50:12,376 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,376 DEBUG [org.jboss.ejb3.entity.ManagedEntityManagerFactory] ************** closing entity managersession **************
      2007-03-20 13:50:12,376 DEBUG [com.arjuna.ats.jta.logging.logger] TransactionImple.getStatus
      2007-03-20 13:50:12,376 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,376 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,376 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,376 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,376 DEBUG [com.arjuna.ats.jta.logging.logger] SynchronizationImple.afterCompletion
      2007-03-20 13:50:12,377 DEBUG [org.jboss.ejb3.entity.ManagedEntityManagerFactory] ************** closing entity managersession **************

        • 1. Re: Jboss 4.2.0CR1 -
          Weston M. Price Master

          This is really a JCA issue and not JBossTS. I am moving this topic where we can take it up there.

          • 2. Re: Jboss 4.2.0CR1 -
            Weston M. Price Master

            Can you please post your *-ds.xml file as well as turn on TRACE for JCA. There is an entry for this in your log4j.xml file, you just need to uncomment it.

            • 3. Re: Jboss 4.2.0CR1 -
              Mark Little Master

              FWIW the error from JBossTS is because something is trying to register a participant in the transaction after it has been marked as rollback-only. We've seen something like this before with Hibernate where it tries to register a Synchronization with a transaction after it's rollback-only: this is invalid.

              • 4. Re: Jboss 4.2.0CR1 -
                olivier merlin Newbie

                Hello Mark and weston,
                First of all, thanks for your help - i really don't know what to do because this code is running without problem on Glassfish .

                Mark,
                I don't see anywhere in my trace that a transaction was previously marked as ROLLBACK-ONLY. When the error occurs, the transaction is rollbacked ( you can see this in my trace ) but before ... i saw nothing on this, neverthess ilooked for this in the whole trace and i have the maximum trace level set in jbossjta-properties.xml :


                How can i see that the transaction was previously marked as rollback ?

                Weston,
                do we still speak of JBossTS - i believed JTA/Arjuna was new in 4.2.x ?
                I don't see how to activate TRACE on JCA in my jboss-log4j.xml - nothing to uncomment ?

                Here is my DS configuration file :
                ---------------------------------------------------


                <local-tx-datasource>

                <jndi-name>jdbc/otainfra-ds</jndi-name>
                <use-java-context>false</use-java-context>
                <connection-url>jdbc:oracle:thin:@londres:1521:MMSERVER</connection-url>

                <driver-class>oracle.jdbc.driver.OracleDriver</driver-class>

                <user-name>demo</user-name>
                demo


                <type-mapping>Oracle9i</type-mapping>

                </local-tx-datasource>


                -------------------------------------------------------------------------

                Thx,
                Olivier

                • 5. Re: Jboss 4.2.0CR1 -
                  olivier merlin Newbie

                  Hello,

                  This is definitavely a JBossTS (arjuna JTA ) transaction problem :
                  We find a workaround : we fix the transaction type to RequiresNew - and surprise it works !


                  This ie not normal - we should be able to stay with Required transtion type - i.e. stay in the transactional context of the calling EJB.
                  The original code with transactional type Required was deployed on Glassfish with success.

                  I suggest to open a bug on this
                  Olivier

                  • 6. Re: Jboss 4.2.0CR1 -
                    Jonathan Halliday Master

                    Olivier, please can you post the part of the stack trace that comes before this? At the start of the trace above, the transaction is already active, but we don't know what has previously been done with it. I suspect hibernate has enlisted a LastResource into it earlier and is trying to do so again, which will cause problems in the version you are running.

                    You could also try grabbing the .jars for the latest stable build from http://repository.jboss.com/jboss/jbossts14/4.2.3.CR4/lib/ and installing them over the top of the existing ones.

                    • 7. Re: Jboss 4.2.0CR1 -
                      olivier merlin Newbie

                      Hi,

                      There is one subtility that can explain the issue :

                      Trans1 ( persistance Unit 1) === (Required) ==> Trans2 (Persistance Unit 2)
                      FAILS with could not enlist ...
                      IMPORTANT : We use a new persistence unit in Trans2

                      Trans1 ( persistance Unit 1) === (RequiresNew) ==> Trans2 (Persistance Unit 2)
                      WORKS !

                      The problem is perhaps related to the usage of 2 persistence unit when we joined the new transaction with Required

                      I will attach the trace for the 2 scenarios
                      regards,

                      • 8. Re: Jboss 4.2.0CR1 -
                        Mark Little Master

                         

                        "omerlin" wrote:
                        Hello Mark and weston,
                        First of all, thanks for your help - i really don't know what to do because this code is running without problem on Glassfish .

                        Mark,
                        I don't see anywhere in my trace that a transaction was previously marked as ROLLBACK-ONLY.


                        Caused by: org.jboss.resource.JBossResourceException: Could not enlist in transaction on entering meta-aware object!; - nested throwable: (javax.transaction.SystemException: java.lang.Throwable: Unabled to enlist resource, see the previous warnings. tx=TransactionImple < ac, BasicAction: a0aa44a:cf61:45ffd85c:49 status: ActionStatus.ABORT_ONLY >)


                        indicates to me that the transaction has been marked as rollback-only. If a transaction is rolled back then it doesn't go through the ABORT_ONLY stage. This typically only happens a) if the application calls setRollbackOnly, or b) if a timeout goes off for the transaction and it can't be rolled back immediately, for some reason.

                        I can't tell whether this is the cause of the problem or a symptom though, from the current stack trace.

                        • 9. Re: Jboss 4.2.0CR1 -
                          olivier merlin Newbie

                          Hi Mark,

                          We don't see any SetRollbackOnly in this part of code .
                          Is it possible to get the current transaction in the code and see if it is marked as RollbackOnly ?
                          We could add this code just before the failure .

                          I'm sure it's not the timeout hypothesis - the failure occurs immediatly

                          rgds,
                          Olivier

                          • 10. Re: Jboss 4.2.0CR1 -
                            Kevin Conner Master

                            This issue is caused by multiple LRCO resources being enlisted in the transaction. This is explicitly forbidden in the current TS codebase as it is transactionally unsound.

                            More information on http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4030881#4030881