BitronixHeuristicMixedException with DataBase message Rolledback but Jms message Sent

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

BitronixHeuristicMixedException with DataBase message Rolledback but Jms message Sent

nandu
This post was updated on .
Hello Team,

We are using Springbatch,websphereMQ,hibernate,Jdbc,jms in our project.After lots of research and checking various blogs started using Bitronix and it is working well our batches run continuously. But we get an exception,once in a while or once in 2 days which is not reproducible what happens is database is Rolled back but still JMS message is sent.We are currently in testing phase and this is a blocking point for me to proceed further:

These are the jars we use for Bitronix:
btm-2.1.4.jar,jta-1.1.jar,geronimo-jms-1.1.1.jar,slf4j-log4j12-1.6.0.jar,slf4j-api-1.6.0.jar

This is our configuration:

<bean id="bitronixConnectionFactory" class="bitronix.tm.resource.jms.PoolingConnectionFactory" init-method="init" destroy-method="close">
    <property name="className" value="com.ibm.mq.jms.MQXAQueueConnectionFactory" />
    <property name="uniqueName" value="MQSeries_XA_RMI_${batch.name}_${env}" />
    <property name="maxPoolSize" value="${mqxa.maxPoolSize}" />
    <property name="driverProperties">
        <props>
                 <prop key="hostName">${jms.host.name}</prop>
                 <prop key="channel">${jms.channel.name}</prop>
                 <prop key="queueManager">${jms.queue.manager}</prop>     
                 <prop key="transportType">${jms.transport.type}</prop>
                 <prop key="port">${jms.host.port}</prop>   
        </props>
    </property>
</bean>
 
 
      <bean id="dataSourceXA" class="bitronix.tm.resource.jdbc.PoolingDataSource" init-method="init" destroy-method="close">
          <property name="className" value="oracle.jdbc.xa.client.OracleXADataSource" />
          <property name="uniqueName" value="XAOracleDS" />
          <property name="maxPoolSize" value="5" />
          <property name="allowLocalTransactions" value="true" />
          <property name="driverProperties">
           <props>
              <prop key="user">${jdbc.username}</prop>
              <prop key="password">${jdbc.password}</prop>
              <prop key="URL">${jdbc.url}</prop>
            </props>
        </property>
    </bean>
   
 

<bean id="btmConfig" factory-method="getConfiguration" class="bitronix.tm.TransactionManagerServices">
    <property name="serverId" value="spring-btm" />
    <property name="defaultTransactionTimeout" value="${bitronix.tm.timer.defaultTransactionTimeout}"/>
    <property name="backgroundRecoveryIntervalSeconds" value="${bitronix.tm.timer.backgroundRecoveryIntervalSeconds}"/>
    <property name="currentNodeOnlyRecovery" value="${bitronix.tm.currentNodeOnlyRecovery}"/>
</bean>
 
 
 

<bean id="BitronixTransactionManager" factory-method="getTransactionManager"
    class="bitronix.tm.TransactionManagerServices" depends-on="btmConfig" destroy-method="shutdown" />
 
 
    <bean id="transactionManagerXA"  class="org.springframework.transaction.jta.JtaTransactionManager">
          <property name="transactionManager" ref="BitronixTransactionManager" />
          <property name="userTransaction" ref="BitronixTransactionManager" />
          <property name="allowCustomIsolationLevels" value="true" />
  </bean>
 
 
 
  <bean id="sessionFactoryXA" class="com.sgcib.crs.treso.infra.orm.hibernate.AnnotationSessionFactoryBean">
   <property name="dataSource" ref="dataSourceXA" />
    <property name="hibernateProperties">
      <props>
        <prop key="hibernate.transaction.factory_class">org.hibernate.transaction.JTATransactionFactory</prop>
        <prop key="hibernate.transaction.manager_lookup_class">org.hibernate.transaction.BTMTransactionManagerLookup</prop>

        <prop key="hibernate.dialect">org.hibernate.dialect.OracleDialect</prop>
        <prop key="hibernate.cache.use_query_cache">${hibernate.cache.enabled}</prop>
        <prop key="hibernate.cache.use_second_level_cache">${hibernate.cache.enabled}</prop>
        <prop key="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</prop>
        <prop key="hibernate.generate_statistics">${hibernate.statistics.enabled}</prop>
        <prop key="hibernate.cache.use_structured_entries">${hibernate.statistics.enabled}</prop>
        <prop key="hibernate.jdbc.batch_size">${hibernate.batch.size}</prop>
        <prop key="hibernate.jdbc.fetch_size">${hibernate.fetch.size}</prop>
        <prop key="hibernate.order_inserts">true</prop>
        <prop key="hibernate.current_session_context_class">jta</prop>
        <prop key="hibernate.show_sql">${hibernate.show_sql}</prop>
        <prop key="hibernate.jdbc.wrap_result_sets">true</prop>
      </props>
    </property>
</bean>


This is the exception log which we get:

03:35:55 [DEBUG] transaction status is changing from PREPARED to COMMITTING - executing 0 listener(s) (thread: main -> bitronix.tm.BitronixTransaction.fireTr
ansactionStatusChangedEvent(BitronixTransaction.java:405))
03:35:55 [DEBUG] executing phase on 3 resource(s) enlisted in 1 position(s) in reverse position order (thread: main -> bitronix.tm.twopc.AbstractPhaseEngine.
executePhase(AbstractPhaseEngine.java:67))
03:35:55 [DEBUG] running 3 job(s) for position '1' (thread: main -> bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine.java:84))
03:35:55 [DEBUG] committing resource an XAResourceHolderState with uniqueName=MQSeries_XA_RMI_test_PER XAResource=com.ibm.mq.jmqi.JmqiXAResource@50e8af
 (ended) with XID a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF36B00003CE0] (thread: main -> bitronix.tm.t
wopc.Committer$CommitJob.commitResource(Committer.java:201))
03:35:55 [DEBUG] committed resource an XAResourceHolderState with uniqueName=MQSeries_XA_RMI_test_PER XAResource=com.ibm.mq.jmqi.JmqiXAResource@50e8af
(ended) with XID a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF36B00003CE0] (thread: main -> bitronix.tm.tw
opc.Committer$CommitJob.commitResource(Committer.java:204))
03:35:55 [DEBUG] committing resource an XAResourceHolderState with uniqueName=XAOracleDS XAResource=oracle.jdbc.driver.T4CXAResource@33b503 (ended) with XID
a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF2C500003CDF] (thread: main -> bitronix.tm.twopc.Committer$Com
mitJob.commitResource(Committer.java:201))
03:35:55 [DEBUG] skipping not participating resource an XAResourceHolderState with uniqueName=XAOracleDS XAResource=oracle.jdbc.driver.T4CXAResource@150ed68
(ended) with XID a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF27A00003CDE] (thread: main -> bitronix.tm.tw
opc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:116))
03:35:55 [DEBUG] error executing a CommitJob with an XAResourceHolderState with uniqueName=XAOracleDS XAResource=oracle.jdbc.driver.T4CXAResource@33b503 (end
ed) with XID a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF2C500003CDF], errorCode=XA_HEURHAZ (thread: main
 -> bitronix.tm.twopc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:138))
03:35:55 [DEBUG] phase executed with 1 exception(s) (thread: main -> bitronix.tm.twopc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:149))
03:35:55 [DEBUG] 1 error(s) happened during execution of position '1' (thread: main -> bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine
.java:87))
03:35:55 [ERROR] resource XAOracleDS failed on a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF2C500003CDF] (
thread: main -> bitronix.tm.twopc.AbstractPhaseEngine.logFailedResources(AbstractPhaseEngine.java:179))
bitronix.tm.internal.BitronixXAException: unknown heuristic termination, global state of this transaction is unknown - guilty: an XAResourceHolderState with
uniqueName=XAOracleDS XAResource=oracle.jdbc.driver.T4CXAResource@33b503 (ended) with XID a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 7370
72696E672D62746D000000048FAFF2C500003CDF]
        at bitronix.tm.twopc.Committer$CommitJob.handleXAException(Committer.java:217)
        at bitronix.tm.twopc.Committer$CommitJob.commitResource(Committer.java:206)
        at bitronix.tm.twopc.Committer$CommitJob.execute(Committer.java:191)
        at bitronix.tm.twopc.executor.Job.run(Job.java:72)
        at bitronix.tm.twopc.executor.SyncExecutor.submit(SyncExecutor.java:31)
        at bitronix.tm.twopc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:121)
        at bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine.java:85)
        at bitronix.tm.twopc.Committer.commit(Committer.java:86)
        at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:289)
        at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:143)
        at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1028)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
        at org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:264)
        at org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:76)
        at org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:367)
        at org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:214)
        at org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:143)
        at org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:250)
        at org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:195)
        at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:135)
        at org.springframework.batch.core.job.flow.JobFlowExecutor.executeStep(JobFlowExecutor.java:61)
  at org.springframework.batch.core.job.flow.support.state.StepState.handle(StepState.java:60)
        at org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:144)
        at org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:124)
        at org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:135)
        at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:293)
        at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:120)
        at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:49)
        at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:114)
        at org.springframework.batch.core.launch.support.CommandLineJobRunner.start(CommandLineJobRunner.java:349)
        at org.springframework.batch.core.launch.support.CommandLineJobRunner.main(CommandLineJobRunner.java:574)
Caused by: oracle.jdbc.xa.OracleXAException
        at oracle.jdbc.xa.OracleXAResource.checkError(OracleXAResource.java:1040)
        at oracle.jdbc.xa.client.OracleXAResource.commit(OracleXAResource.java:573)
        at bitronix.tm.twopc.Committer$CommitJob.commitResource(Committer.java:202)
        ... 31 more
03:35:55 [DEBUG] changing transaction status to UNKNOWN (thread: main -> bitronix.tm.BitronixTransaction.setStatus(BitronixTransaction.java:385))
03:35:55 [DEBUG] between 296 and 399, writing a Bitronix TransactionLogRecord with status=UNKNOWN, recordLength=95, headerLength=28, time=19590553793, sequen
ceNumber=19512, crc32=931835391, gtrid=737072696E672D62746D000000048FAFF26200003CDD, uniqueNames=MQSeries_XA_RMI_test_PER,XAOracleDS (thread: main -> b
itronix.tm.journal.TransactionLogAppender.writeLog(TransactionLogAppender.java:100))
03:35:55 [DEBUG] disk journal appender now at position 399 (thread: main -> bitronix.tm.journal.TransactionLogAppender.writeLog(TransactionLogAppender.java:1
24))
03:35:55 [DEBUG] transaction status is changing from COMMITTING to UNKNOWN - executing 0 listener(s) (thread: main -> bitronix.tm.BitronixTransaction.fireTra
nsactionStatusChangedEvent(BitronixTransaction.java:405))
03:35:55 [DEBUG] clearing XAResourceHolder states on 3 resource(s) (thread: main -> bitronix.tm.internal.XAResourceManager.clearXAResourceHolderStates(XAReso
urceManager.java:235))
03:35:55 [DEBUG] removing XAResourceHolderState of xid a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF27A000
03CDE] from a JdbcPooledConnection from datasource XAOracleDS in state NOT_ACCESSIBLE with usage count 0 wrapping oracle.jdbc.driver.T4CXAConnection@6d23ea (
thread: main -> bitronix.tm.resource.common.AbstractXAResourceHolder.removeXAResourceHolderState(AbstractXAResourceHolder.java:77))
03:35:55 [DEBUG] resource a JdbcPooledConnection from datasource XAOracleDS in state NOT_ACCESSIBLE with usage count 0 wrapping oracle.jdbc.driver.T4CXAConne
ction@6d23ea cleaned up all transaction states for GTRID [737072696E672D62746D000000048FAFF26200003CDD] (thread: main -> bitronix.tm.internal.XAResourceManag
er.clearXAResourceHolderStates(XAResourceManager.java:246))
03:35:55 [DEBUG] removing XAResourceHolderState of xid a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF2C5000
03CDF] from a JdbcPooledConnection from datasource XAOracleDS in state NOT_ACCESSIBLE with usage count 0 wrapping oracle.jdbc.driver.T4CXAConnection@157402b
(thread: main -> bitronix.tm.resource.common.AbstractXAResourceHolder.removeXAResourceHolderState(AbstractXAResourceHolder.java:77))
03:35:55 [DEBUG] resource a JdbcPooledConnection from datasource XAOracleDS in state NOT_ACCESSIBLE with usage count 0 wrapping oracle.jdbc.driver.T4CXAConne
ction@157402b cleaned up all transaction states for GTRID [737072696E672D62746D000000048FAFF26200003CDD] (thread: main -> bitronix.tm.internal.XAResourceMana
ger.clearXAResourceHolderStates(XAResourceManager.java:246))
03:35:55 [DEBUG] removing XAResourceHolderState of xid a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF36B000
03CE0] from a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE with underlying conn
ection com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main -> bitronix.tm.resource.common.AbstractXAResourceHolder.removeXAResourceHolderState(AbstractXA
ResourceHolder.java:77))
03:35:55 [DEBUG] resource a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE with u
nderlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 cleaned up all transaction states for GTRID [737072696E672D62746D000000048FAFF26200003CDD] (th
read: main -> bitronix.tm.internal.XAResourceManager.clearXAResourceHolderStates(XAResourceManager.java:246))
03:35:55 [DEBUG] after completion, 4 synchronization(s) to execute (thread: main -> bitronix.tm.BitronixTransaction.fireAfterCompletionEvent(BitronixTransact
ion.java:545))
03:35:55 [DEBUG] executing synchronization org.hibernate.transaction.CacheSynchronization with status=UNKNOWN (thread: main -> bitronix.tm.BitronixTransactio
n.fireAfterCompletionEvent(BitronixTransaction.java:548))
03:35:55 [DEBUG] executing synchronization a ClearContextSynchronization for a Bitronix Transaction with GTRID [737072696E672D62746D000000048FAFF26200003CDD]
, status=UNKNOWN, 0 resource(s) enlisted (started Sat Aug 15 18:49:01 MET 1970) with status=UNKNOWN (thread: main -> bitronix.tm.BitronixTransaction.fireAfte
rCompletionEvent(BitronixTransaction.java:548))
03:35:55 [DEBUG] clearing thread context: a ThreadContext with transaction a Bitronix Transaction with GTRID [737072696E672D62746D000000048FAFF26200003CDD],
status=UNKNOWN, 0 resource(s) enlisted (started Sat Aug 15 18:49:01 MET 1970), default timeout 10s (thread: main -> bitronix.tm.BitronixTransactionManager$Cl
earContextSynchronization.afterCompletion(BitronixTransactionManager.java:468))
03:35:55 [DEBUG] executing synchronization a DeferredReleaseSynchronization of a JdbcPooledConnection from datasource XAOracleDS in state NOT_ACCESSIBLE with
 usage count 0 wrapping oracle.jdbc.driver.T4CXAConnection@6d23ea with status=UNKNOWN (thread: main -> bitronix.tm.BitronixTransaction.fireAfterCompletionEve
nt(BitronixTransaction.java:548))
03:35:55 [DEBUG] notifying 2 stateChangeEventListener(s) about state changed from NOT_ACCESSIBLE to IN_POOL in a JdbcPooledConnection from datasource XAOracl
eDS in state IN_POOL with usage count 0 wrapping oracle.jdbc.driver.T4CXAConnection@157402b (thread: main -> bitronix.tm.resource.common.AbstractXAStatefulHo
lder.fireStateChanged(AbstractXAStatefulHolder.java:80))
03:35:55 [DEBUG] requeued JDBC connection of a PoolingDataSource containing an XAPool of resource XAOracleDS with 4 connection(s) (3 still available) (thread
: main -> bitronix.tm.resource.jdbc.JdbcPooledConnection.stateChanged(JdbcPooledConnection.java:317))
03:35:55 [DEBUG] a connection's state changed to IN_POOL, notifying a thread eventually waiting for a connection (thread: main -> bitronix.tm.resource.common
.XAPool.stateChanged(XAPool.java:202))
03:35:55 [DEBUG] DeferredReleaseSynchronization requeued a JdbcPooledConnection from datasource XAOracleDS in state IN_POOL with usage count 0 wrapping oracl
e.jdbc.driver.T4CXAConnection@157402b (thread: main -> bitronix.tm.resource.common.DeferredReleaseSynchronization.afterCompletion(DeferredReleaseSynchronizat
ion.java:53))
03:35:55 [INFO ] Commit failed while step execution data was already updated. Reverting to old version. (thread: main -> org.springframework.batch.core.step.
tasklet.TaskletStep$ChunkTransactionCallback.afterCompletion(TaskletStep.java:342))
03:35:55 [ERROR] Rolling back with transaction in unknown state (thread: main -> org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCall
back.afterCompletion(TaskletStep.java:351))
03:35:55 [DEBUG] closing a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE with un
derlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main -> bitronix.tm.resource.jms.DualSessionWrapper.close(DualSessionWrapper.java:167)
)
03:35:55 [DEBUG] delisting a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE with
underlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 from null (thread: main -> bitronix.tm.resource.common.TransactionContextHelper.delistFromCur
rentTransaction(TransactionContextHelper.java:93))
03:35:55 [DEBUG] resource is not in enlisting global transaction context: a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQSeries_
XA_RMI_test_PER in state ACCESSIBLE with underlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main -> bitronix.tm.resource.common.T
ransactionContextHelper.isInEnlistingGlobalTransactionContext(TransactionContextHelper.java:234))
03:35:55 [DEBUG] requeuing a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE with
underlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 from null (thread: main -> bitronix.tm.resource.common.TransactionContextHelper.requeue(Trans
actionContextHelper.java:132))
03:35:55 [DEBUG] resource is not in enlisting global transaction context: a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQSeries_
XA_RMI_test_PER in state ACCESSIBLE with underlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main -> bitronix.tm.resource.common.T
ransactionContextHelper.isInEnlistingGlobalTransactionContext(TransactionContextHelper.java:234))
03:35:55 [DEBUG] looking in in-flight transactions for XAResourceHolderState of a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQS
eries_XA_RMI_test_PER in state ACCESSIBLE with underlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main -> bitronix.tm.resource.co
mmon.TransactionContextHelper.isEnlistedInSomeTransaction(TransactionContextHelper.java:204))
03:35:55 [DEBUG] resource not enlisted in any transaction: a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool MQSeries_XA_RMI_bir_envc
pa_PER in state ACCESSIBLE with underlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main -> bitronix.tm.resource.common.AbstractXAResour
ceHolder.hasStateForXAResource(AbstractXAResourceHolder.java:110))
03:35:55 [DEBUG] a connection's state changed to IN_POOL, notifying a thread eventually waiting for a connection (thread: main -> bitronix.tm.resource.common
.XAPool.stateChanged(XAPool.java:202))
03:35:55 [DEBUG] released to pool a JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state IN_POOL with underlying connection com.ibm.mq.jms.MQX
AQueueConnection@8beff2 (thread: main -> bitronix.tm.resource.jms.JmsPooledConnection.release(JmsPooledConnection.java:163))
03:35:55 [ERROR] Encountered an error executing the step (thread: main -> org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:222))
org.springframework.transaction.HeuristicCompletionException: Heuristic completion: outcome state is mixed; nested exception is bitronix.tm.internal.Bitronix
HeuristicMixedException: transaction failed during commit of a Bitronix Transaction with GTRID [737072696E672D62746D000000048FAFF26200003CDD], status=UNKNOWN
, 3 resource(s) enlisted (started Sat Aug 15 18:49:01 MET 1970): resource(s) [XAOracleDS] improperly unilaterally rolled back (or hazard happened)
        at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1035)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
        at org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:264)
        at org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:76)
        at org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:367)
        at org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:214)
        at org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:143)
        at org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:250)
        at org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:195)
        at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:135)
        at org.springframework.batch.core.job.flow.JobFlowExecutor.executeStep(JobFlowExecutor.java:61)
        at org.springframework.batch.core.job.flow.support.state.StepState.handle(StepState.java:60)
        at org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:144)
        at org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:124)
        at org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:135)
        at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:293)
        at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:120)
        at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:49)
        at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:114)
        at org.springframework.batch.core.launch.support.CommandLineJobRunner.start(CommandLineJobRunner.java:349)
        at org.springframework.batch.core.launch.support.CommandLineJobRunner.main(CommandLineJobRunner.java:574)
Caused by: bitronix.tm.internal.BitronixHeuristicMixedException: transaction failed during commit of a Bitronix Transaction with GTRID [737072696E672D62746D0
00000048FAFF26200003CDD], status=UNKNOWN, 3 resource(s) enlisted (started Sat Aug 15 18:49:01 MET 1970): resource(s) [XAOracleDS] improperly unilaterally rol
led back (or hazard happened)
        at bitronix.tm.twopc.Committer.throwException(Committer.java:156)
        at bitronix.tm.twopc.Committer.commit(Committer.java:94)
        at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:289)
        at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:143)
        at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1028)
        ... 22 more
Caused by: bitronix.tm.twopc.PhaseException: collected 1 exception(s):
 [XAOracleDS - bitronix.tm.internal.BitronixXAException(XA_HEURHAZ) - unknown heuristic termination, global state of this transaction is unknown - guilty: an
 XAResourceHolderState with uniqueName=XAOracleDS XAResource=oracle.jdbc.driver.T4CXAResource@33b503 (ended) with XID a Bitronix XID [737072696E672D62746D000
000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF2C500003CDF]]
        at bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine.java:104)
        at bitronix.tm.twopc.Committer.commit(Committer.java:86)
        ... 25 more

I can not find any information about it. Can anyone please help me?

Thanks in advance





 
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: BitronixHeuristicMixedException with DataBase message Rolledback but Jms message is Sent with

Ludovic Orban-2
There could be many reasons why the Oracle driver would throw a
heuristic hazard exception. The first thing that surprises me is that
despite you reported using BTM 2.1.4, the XA exception analyzer did
not report the ORA-*** error code. That's too bad because that would
have been your first indicator of what's going on.

When the XA exception analyzer does it job, you get error messages
looking like this:

 "error executing ... , errorCode=XA_HEURHAZ, extra error=ORA-xxx"

instead of the ones you get which look like this:

 "error executing ... , errorCode=XA_HEURHAZ"

without the extra error being reported. You should probably start by
trying to figure out why you don't get this extra error.


Ouf of the blue, I also wonder if you're running multiple instances of
your software in parallel, ie: in a cluster. If that's the case, then
the fact that you hardcoded the serverId like this:

<property name="serverId" value="spring-btm" />

could explain why you get some heuritic errors from time to time.
Every single server in a cluster must have a different serverId, and
those serverId's must stay the same across restarts. If you fail with
the first condition, it could very well be that another server's
recovery engine racily rolls back another server's in-flight
transaction falsely believing it is one of its own. If you fail with
the second condition, then recovery won't work across restarts.

Short of that, checking the Oracle logs to try to figure out why the
server heuristically rolled back some transactions could give you some
clue.

--
Ludovic

On Tue, Jan 13, 2015 at 9:31 AM, nandu <[hidden email]> wrote:

> Hello Team,
>
> We are using Springbatch,websphereMQ,hibernate,Jdbc,jms in our project.After
> lots of research and checking various blogs started using Bitronix and it is
> working well our batches run continuously. But we get an exception,once in a
> while or once in 2 days which is not reproducible what happens is database
> is Rolled back but still JMS message is sent.We are currently in testing
> phase and this is a blocking point for me to proceed further:
>
> These are the jars we use for Bitronix:
> btm-2.1.4.jar,jta-1.1.jar,geronimo-jms-1.1.1.jar,slf4j-log4j12-1.6.0.jar,slf4j-api-1.6.0.jar
>
> This is our configuration:
>
> <bean id="bitronixConnectionFactory"
> class="bitronix.tm.resource.jms.PoolingConnectionFactory" init-method="init"
> destroy-method="close">
>     <property name="className"
> value="com.ibm.mq.jms.MQXAQueueConnectionFactory" />
>     <property name="uniqueName" value="MQSeries_XA_RMI_${batch.name}_${env}"
> />
>     <property name="maxPoolSize" value="${mqxa.maxPoolSize}" />
>     <property name="driverProperties">
>         <props>
>                  <prop key="hostName">${jms.host.name}</prop>
>                  <prop key="channel">${jms.channel.name}</prop>
>                  <prop key="queueManager">${jms.queue.manager}</prop>
>                  <prop key="transportType">${jms.transport.type}</prop>
>                  <prop key="port">${jms.host.port}</prop>
>         </props>
>     </property>
> </bean>
>
>
>       <bean id="dataSourceXA"
> class="bitronix.tm.resource.jdbc.PoolingDataSource" init-method="init"
> destroy-method="close">
>           <property name="className"
> value="oracle.jdbc.xa.client.OracleXADataSource" />
>           <property name="uniqueName" value="XAOracleDS" />
>           <property name="maxPoolSize" value="5" />
>           <property name="allowLocalTransactions" value="true" />
>           <property name="driverProperties">
>            <props>
>               <prop key="user">${jdbc.username}</prop>
>               <prop key="password">${jdbc.password}</prop>
>               <prop key="URL">${jdbc.url}</prop>
>             </props>
>         </property>
>     </bean>
>
>
>
> <bean id="btmConfig" factory-method="getConfiguration"
> class="bitronix.tm.TransactionManagerServices">
>     <property name="serverId" value="spring-btm" />
>     <property name="defaultTransactionTimeout"
> value="${bitronix.tm.timer.defaultTransactionTimeout}"/>
>     <property name="backgroundRecoveryIntervalSeconds"
> value="${bitronix.tm.timer.backgroundRecoveryIntervalSeconds}"/>
>     <property name="currentNodeOnlyRecovery"
> value="${bitronix.tm.currentNodeOnlyRecovery}"/>
> </bean>
>
>
>
>
> <bean id="BitronixTransactionManager" factory-method="getTransactionManager"
>     class="bitronix.tm.TransactionManagerServices" depends-on="btmConfig"
> destroy-method="shutdown" />
>
>
>     <bean id="transactionManagerXA"
> class="org.springframework.transaction.jta.JtaTransactionManager">
>           <property name="transactionManager"
> ref="BitronixTransactionManager" />
>           <property name="userTransaction" ref="BitronixTransactionManager"
> />
>           <property name="allowCustomIsolationLevels" value="true" />
>   </bean>
>
>
>
>   <bean id="sessionFactoryXA"
> class="com.sgcib.crs.treso.infra.orm.hibernate.AnnotationSessionFactoryBean">
>    <property name="dataSource" ref="dataSourceXA" />
>     <property name="hibernateProperties">
>       <props>
>         <prop
> key="hibernate.transaction.factory_class">org.hibernate.transaction.JTATransactionFactory</prop>
>         <prop
> key="hibernate.transaction.manager_lookup_class">org.hibernate.transaction.BTMTransactionManagerLookup</prop>
>
>         <prop
> key="hibernate.dialect">org.hibernate.dialect.OracleDialect</prop>
>         <prop
> key="hibernate.cache.use_query_cache">${hibernate.cache.enabled}</prop>
>         <prop
> key="hibernate.cache.use_second_level_cache">${hibernate.cache.enabled}</prop>
>         <prop
> key="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</prop>
>         <prop
> key="hibernate.generate_statistics">${hibernate.statistics.enabled}</prop>
>         <prop
> key="hibernate.cache.use_structured_entries">${hibernate.statistics.enabled}</prop>
>         <prop key="hibernate.jdbc.batch_size">${hibernate.batch.size}</prop>
>         <prop key="hibernate.jdbc.fetch_size">${hibernate.fetch.size}</prop>
>         <prop key="hibernate.order_inserts">true</prop>
>         <prop key="hibernate.current_session_context_class">jta</prop>
>         <prop key="hibernate.show_sql">${hibernate.show_sql}</prop>
>         <prop key="hibernate.jdbc.wrap_result_sets">true</prop>
>       </props>
>     </property>
> </bean>
>
>
> This is the exception log which we get:
>
> 03:35:55 [DEBUG] transaction status is changing from PREPARED to COMMITTING
> - executing 0 listener(s) (thread: main ->
> bitronix.tm.BitronixTransaction.fireTr
> ansactionStatusChangedEvent(BitronixTransaction.java:405))
> 03:35:55 [DEBUG] executing phase on 3 resource(s) enlisted in 1 position(s)
> in reverse position order (thread: main ->
> bitronix.tm.twopc.AbstractPhaseEngine.
> executePhase(AbstractPhaseEngine.java:67))
> 03:35:55 [DEBUG] running 3 job(s) for position '1' (thread: main ->
> bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine.java:84))
> 03:35:55 [DEBUG] committing resource an XAResourceHolderState with
> uniqueName=MQSeries_XA_RMI_test_PER
> XAResource=com.ibm.mq.jmqi.JmqiXAResource@50e8af
>  (ended) with XID a Bitronix XID
> [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF36B00003CE0] (thread: main -> bitronix.tm.t
> wopc.Committer$CommitJob.commitResource(Committer.java:201))
> 03:35:55 [DEBUG] committed resource an XAResourceHolderState with
> uniqueName=MQSeries_XA_RMI_test_PER
> XAResource=com.ibm.mq.jmqi.JmqiXAResource@50e8af
> (ended) with XID a Bitronix XID
> [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF36B00003CE0] (thread: main ->
> bitronix.tm.tw
> opc.Committer$CommitJob.commitResource(Committer.java:204))
> 03:35:55 [DEBUG] committing resource an XAResourceHolderState with
> uniqueName=XAOracleDS XAResource=oracle.jdbc.driver.T4CXAResource@33b503
> (ended) with XID
> a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF2C500003CDF] (thread: main ->
> bitronix.tm.twopc.Committer$Com
> mitJob.commitResource(Committer.java:201))
> 03:35:55 [DEBUG] skipping not participating resource an
> XAResourceHolderState with uniqueName=XAOracleDS
> XAResource=oracle.jdbc.driver.T4CXAResource@150ed68
> (ended) with XID a Bitronix XID
> [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF27A00003CDE] (thread: main ->
> bitronix.tm.tw
> opc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:116))
> 03:35:55 [DEBUG] error executing a CommitJob with an XAResourceHolderState
> with uniqueName=XAOracleDS
> XAResource=oracle.jdbc.driver.T4CXAResource@33b503 (end
> ed) with XID a Bitronix XID [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF2C500003CDF], errorCode=XA_HEURHAZ (thread:
> main
>  ->
> bitronix.tm.twopc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:138))
> 03:35:55 [DEBUG] phase executed with 1 exception(s) (thread: main ->
> bitronix.tm.twopc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:149))
> 03:35:55 [DEBUG] 1 error(s) happened during execution of position '1'
> (thread: main ->
> bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine
> .java:87))
> 03:35:55 [ERROR] resource XAOracleDS failed on a Bitronix XID
> [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF2C500003CDF] (
> thread: main ->
> bitronix.tm.twopc.AbstractPhaseEngine.logFailedResources(AbstractPhaseEngine.java:179))
> bitronix.tm.internal.BitronixXAException: unknown heuristic termination,
> global state of this transaction is unknown - guilty: an
> XAResourceHolderState with
> uniqueName=XAOracleDS XAResource=oracle.jdbc.driver.T4CXAResource@33b503
> (ended) with XID a Bitronix XID
> [737072696E672D62746D000000048FAFF26200003CDD : 7370
> 72696E672D62746D000000048FAFF2C500003CDF]
>         at
> bitronix.tm.twopc.Committer$CommitJob.handleXAException(Committer.java:217)
>         at
> bitronix.tm.twopc.Committer$CommitJob.commitResource(Committer.java:206)
>         at bitronix.tm.twopc.Committer$CommitJob.execute(Committer.java:191)
>         at bitronix.tm.twopc.executor.Job.run(Job.java:72)
>         at
> bitronix.tm.twopc.executor.SyncExecutor.submit(SyncExecutor.java:31)
>         at
> bitronix.tm.twopc.AbstractPhaseEngine.runJobsForPosition(AbstractPhaseEngine.java:121)
>         at
> bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine.java:85)
>         at bitronix.tm.twopc.Committer.commit(Committer.java:86)
>         at
> bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:289)
>         at
> bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:143)
>         at
> org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1028)
>         at
> org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
>         at
> org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
>         at
> org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
>         at
> org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:264)
>         at
> org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:76)
>         at
> org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:367)
>         at
> org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:214)
>         at
> org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:143)
>         at
> org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:250)
>         at
> org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:195)
>         at
> org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:135)
>         at
> org.springframework.batch.core.job.flow.JobFlowExecutor.executeStep(JobFlowExecutor.java:61)
>   at
> org.springframework.batch.core.job.flow.support.state.StepState.handle(StepState.java:60)
>         at
> org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:144)
>         at
> org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:124)
>         at
> org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:135)
>         at
> org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:293)
>         at
> org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:120)
>         at
> org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:49)
>         at
> org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:114)
>         at
> org.springframework.batch.core.launch.support.CommandLineJobRunner.start(CommandLineJobRunner.java:349)
>         at
> org.springframework.batch.core.launch.support.CommandLineJobRunner.main(CommandLineJobRunner.java:574)
> Caused by: oracle.jdbc.xa.OracleXAException
>         at
> oracle.jdbc.xa.OracleXAResource.checkError(OracleXAResource.java:1040)
>         at
> oracle.jdbc.xa.client.OracleXAResource.commit(OracleXAResource.java:573)
>         at
> bitronix.tm.twopc.Committer$CommitJob.commitResource(Committer.java:202)
>         ... 31 more
> 03:35:55 [DEBUG] changing transaction status to UNKNOWN (thread: main ->
> bitronix.tm.BitronixTransaction.setStatus(BitronixTransaction.java:385))
> 03:35:55 [DEBUG] between 296 and 399, writing a Bitronix
> TransactionLogRecord with status=UNKNOWN, recordLength=95, headerLength=28,
> time=19590553793, sequen
> ceNumber=19512, crc32=931835391,
> gtrid=737072696E672D62746D000000048FAFF26200003CDD,
> uniqueNames=MQSeries_XA_RMI_test_PER,XAOracleDS (thread: main -> b
> itronix.tm.journal.TransactionLogAppender.writeLog(TransactionLogAppender.java:100))
> 03:35:55 [DEBUG] disk journal appender now at position 399 (thread: main ->
> bitronix.tm.journal.TransactionLogAppender.writeLog(TransactionLogAppender.java:1
> 24))
> 03:35:55 [DEBUG] transaction status is changing from COMMITTING to UNKNOWN -
> executing 0 listener(s) (thread: main ->
> bitronix.tm.BitronixTransaction.fireTra
> nsactionStatusChangedEvent(BitronixTransaction.java:405))
> 03:35:55 [DEBUG] clearing XAResourceHolder states on 3 resource(s) (thread:
> main ->
> bitronix.tm.internal.XAResourceManager.clearXAResourceHolderStates(XAReso
> urceManager.java:235))
> 03:35:55 [DEBUG] removing XAResourceHolderState of xid a Bitronix XID
> [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF27A000
> 03CDE] from a JdbcPooledConnection from datasource XAOracleDS in state
> NOT_ACCESSIBLE with usage count 0 wrapping
> oracle.jdbc.driver.T4CXAConnection@6d23ea (
> thread: main ->
> bitronix.tm.resource.common.AbstractXAResourceHolder.removeXAResourceHolderState(AbstractXAResourceHolder.java:77))
> 03:35:55 [DEBUG] resource a JdbcPooledConnection from datasource XAOracleDS
> in state NOT_ACCESSIBLE with usage count 0 wrapping
> oracle.jdbc.driver.T4CXAConne
> ction@6d23ea cleaned up all transaction states for GTRID
> [737072696E672D62746D000000048FAFF26200003CDD] (thread: main ->
> bitronix.tm.internal.XAResourceManag
> er.clearXAResourceHolderStates(XAResourceManager.java:246))
> 03:35:55 [DEBUG] removing XAResourceHolderState of xid a Bitronix XID
> [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF2C5000
> 03CDF] from a JdbcPooledConnection from datasource XAOracleDS in state
> NOT_ACCESSIBLE with usage count 0 wrapping
> oracle.jdbc.driver.T4CXAConnection@157402b
> (thread: main ->
> bitronix.tm.resource.common.AbstractXAResourceHolder.removeXAResourceHolderState(AbstractXAResourceHolder.java:77))
> 03:35:55 [DEBUG] resource a JdbcPooledConnection from datasource XAOracleDS
> in state NOT_ACCESSIBLE with usage count 0 wrapping
> oracle.jdbc.driver.T4CXAConne
> ction@157402b cleaned up all transaction states for GTRID
> [737072696E672D62746D000000048FAFF26200003CDD] (thread: main ->
> bitronix.tm.internal.XAResourceMana
> ger.clearXAResourceHolderStates(XAResourceManager.java:246))
> 03:35:55 [DEBUG] removing XAResourceHolderState of xid a Bitronix XID
> [737072696E672D62746D000000048FAFF26200003CDD :
> 737072696E672D62746D000000048FAFF36B000
> 03CE0] from a DualSessionWrapper in state ACCESSIBLE of a
> JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE
> with underlying conn
> ection com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main ->
> bitronix.tm.resource.common.AbstractXAResourceHolder.removeXAResourceHolderState(AbstractXA
> ResourceHolder.java:77))
> 03:35:55 [DEBUG] resource a DualSessionWrapper in state ACCESSIBLE of a
> JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE
> with u
> nderlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 cleaned up
> all transaction states for GTRID
> [737072696E672D62746D000000048FAFF26200003CDD] (th
> read: main ->
> bitronix.tm.internal.XAResourceManager.clearXAResourceHolderStates(XAResourceManager.java:246))
> 03:35:55 [DEBUG] after completion, 4 synchronization(s) to execute (thread:
> main ->
> bitronix.tm.BitronixTransaction.fireAfterCompletionEvent(BitronixTransact
> ion.java:545))
> 03:35:55 [DEBUG] executing synchronization
> org.hibernate.transaction.CacheSynchronization with status=UNKNOWN (thread:
> main -> bitronix.tm.BitronixTransactio
> n.fireAfterCompletionEvent(BitronixTransaction.java:548))
> 03:35:55 [DEBUG] executing synchronization a ClearContextSynchronization for
> a Bitronix Transaction with GTRID
> [737072696E672D62746D000000048FAFF26200003CDD]
> , status=UNKNOWN, 0 resource(s) enlisted (started Sat Aug 15 18:49:01 MET
> 1970) with status=UNKNOWN (thread: main ->
> bitronix.tm.BitronixTransaction.fireAfte
> rCompletionEvent(BitronixTransaction.java:548))
> 03:35:55 [DEBUG] clearing thread context: a ThreadContext with transaction a
> Bitronix Transaction with GTRID
> [737072696E672D62746D000000048FAFF26200003CDD],
> status=UNKNOWN, 0 resource(s) enlisted (started Sat Aug 15 18:49:01 MET
> 1970), default timeout 10s (thread: main ->
> bitronix.tm.BitronixTransactionManager$Cl
> earContextSynchronization.afterCompletion(BitronixTransactionManager.java:468))
> 03:35:55 [DEBUG] executing synchronization a DeferredReleaseSynchronization
> of a JdbcPooledConnection from datasource XAOracleDS in state NOT_ACCESSIBLE
> with
>  usage count 0 wrapping oracle.jdbc.driver.T4CXAConnection@6d23ea with
> status=UNKNOWN (thread: main ->
> bitronix.tm.BitronixTransaction.fireAfterCompletionEve
> nt(BitronixTransaction.java:548))
> 03:35:55 [DEBUG] notifying 2 stateChangeEventListener(s) about state changed
> from NOT_ACCESSIBLE to IN_POOL in a JdbcPooledConnection from datasource
> XAOracl
> eDS in state IN_POOL with usage count 0 wrapping
> oracle.jdbc.driver.T4CXAConnection@157402b (thread: main ->
> bitronix.tm.resource.common.AbstractXAStatefulHo
> lder.fireStateChanged(AbstractXAStatefulHolder.java:80))
> 03:35:55 [DEBUG] requeued JDBC connection of a PoolingDataSource containing
> an XAPool of resource XAOracleDS with 4 connection(s) (3 still available)
> (thread
> : main ->
> bitronix.tm.resource.jdbc.JdbcPooledConnection.stateChanged(JdbcPooledConnection.java:317))
> 03:35:55 [DEBUG] a connection's state changed to IN_POOL, notifying a thread
> eventually waiting for a connection (thread: main ->
> bitronix.tm.resource.common
> .XAPool.stateChanged(XAPool.java:202))
> 03:35:55 [DEBUG] DeferredReleaseSynchronization requeued a
> JdbcPooledConnection from datasource XAOracleDS in state IN_POOL with usage
> count 0 wrapping oracl
> e.jdbc.driver.T4CXAConnection@157402b (thread: main ->
> bitronix.tm.resource.common.DeferredReleaseSynchronization.afterCompletion(DeferredReleaseSynchronizat
> ion.java:53))
> 03:35:55 [INFO ] Commit failed while step execution data was already
> updated. Reverting to old version. (thread: main ->
> org.springframework.batch.core.step.
> tasklet.TaskletStep$ChunkTransactionCallback.afterCompletion(TaskletStep.java:342))
> 03:35:55 [ERROR] Rolling back with transaction in unknown state (thread:
> main ->
> org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCall
> back.afterCompletion(TaskletStep.java:351))
> 03:35:55 [DEBUG] closing a DualSessionWrapper in state ACCESSIBLE of a
> JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE
> with un
> derlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main
> ->
> bitronix.tm.resource.jms.DualSessionWrapper.close(DualSessionWrapper.java:167)
> )
> 03:35:55 [DEBUG] delisting a DualSessionWrapper in state ACCESSIBLE of a
> JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE
> with
> underlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 from null
> (thread: main ->
> bitronix.tm.resource.common.TransactionContextHelper.delistFromCur
> rentTransaction(TransactionContextHelper.java:93))
> 03:35:55 [DEBUG] resource is not in enlisting global transaction context: a
> DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool
> MQSeries_
> XA_RMI_test_PER in state ACCESSIBLE with underlying connection
> com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main ->
> bitronix.tm.resource.common.T
> ransactionContextHelper.isInEnlistingGlobalTransactionContext(TransactionContextHelper.java:234))
> 03:35:55 [DEBUG] requeuing a DualSessionWrapper in state ACCESSIBLE of a
> JmsPooledConnection of pool MQSeries_XA_RMI_test_PER in state ACCESSIBLE
> with
> underlying connection com.ibm.mq.jms.MQXAQueueConnection@8beff2 from null
> (thread: main ->
> bitronix.tm.resource.common.TransactionContextHelper.requeue(Trans
> actionContextHelper.java:132))
> 03:35:55 [DEBUG] resource is not in enlisting global transaction context: a
> DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool
> MQSeries_
> XA_RMI_test_PER in state ACCESSIBLE with underlying connection
> com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main ->
> bitronix.tm.resource.common.T
> ransactionContextHelper.isInEnlistingGlobalTransactionContext(TransactionContextHelper.java:234))
> 03:35:55 [DEBUG] looking in in-flight transactions for XAResourceHolderState
> of a DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool
> MQS
> eries_XA_RMI_test_PER in state ACCESSIBLE with underlying connection
> com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main ->
> bitronix.tm.resource.co
> mmon.TransactionContextHelper.isEnlistedInSomeTransaction(TransactionContextHelper.java:204))
> 03:35:55 [DEBUG] resource not enlisted in any transaction: a
> DualSessionWrapper in state ACCESSIBLE of a JmsPooledConnection of pool
> MQSeries_XA_RMI_bir_envc
> pa_PER in state ACCESSIBLE with underlying connection
> com.ibm.mq.jms.MQXAQueueConnection@8beff2 (thread: main ->
> bitronix.tm.resource.common.AbstractXAResour
> ceHolder.hasStateForXAResource(AbstractXAResourceHolder.java:110))
> 03:35:55 [DEBUG] a connection's state changed to IN_POOL, notifying a thread
> eventually waiting for a connection (thread: main ->
> bitronix.tm.resource.common
> .XAPool.stateChanged(XAPool.java:202))
> 03:35:55 [DEBUG] released to pool a JmsPooledConnection of pool
> MQSeries_XA_RMI_test_PER in state IN_POOL with underlying connection
> com.ibm.mq.jms.MQX
> AQueueConnection@8beff2 (thread: main ->
> bitronix.tm.resource.jms.JmsPooledConnection.release(JmsPooledConnection.java:163))
> 03:35:55 [ERROR] Encountered an error executing the step (thread: main ->
> org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:222))
> org.springframework.transaction.HeuristicCompletionException: Heuristic
> completion: outcome state is mixed; nested exception is
> bitronix.tm.internal.Bitronix
> HeuristicMixedException: transaction failed during commit of a Bitronix
> Transaction with GTRID [737072696E672D62746D000000048FAFF26200003CDD],
> status=UNKNOWN
> , 3 resource(s) enlisted (started Sat Aug 15 18:49:01 MET 1970): resource(s)
> [XAOracleDS] improperly unilaterally rolled back (or hazard happened)
>         at
> org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1035)
>         at
> org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
>         at
> org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
>         at
> org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
>         at
> org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:264)
>         at
> org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:76)
>         at
> org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:367)
>         at
> org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:214)
>         at
> org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:143)
>         at
> org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:250)
>         at
> org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:195)
>         at
> org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:135)
>         at
> org.springframework.batch.core.job.flow.JobFlowExecutor.executeStep(JobFlowExecutor.java:61)
>         at
> org.springframework.batch.core.job.flow.support.state.StepState.handle(StepState.java:60)
>         at
> org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:144)
>         at
> org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:124)
>         at
> org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:135)
>         at
> org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:293)
>         at
> org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:120)
>         at
> org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:49)
>         at
> org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:114)
>         at
> org.springframework.batch.core.launch.support.CommandLineJobRunner.start(CommandLineJobRunner.java:349)
>         at
> org.springframework.batch.core.launch.support.CommandLineJobRunner.main(CommandLineJobRunner.java:574)
> Caused by: bitronix.tm.internal.BitronixHeuristicMixedException: transaction
> failed during commit of a Bitronix Transaction with GTRID
> [737072696E672D62746D0
> 00000048FAFF26200003CDD], status=UNKNOWN, 3 resource(s) enlisted (started
> Sat Aug 15 18:49:01 MET 1970): resource(s) [XAOracleDS] improperly
> unilaterally rol
> led back (or hazard happened)
>         at bitronix.tm.twopc.Committer.throwException(Committer.java:156)
>         at bitronix.tm.twopc.Committer.commit(Committer.java:94)
>         at
> bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:289)
>         at
> bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:143)
>         at
> org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1028)
>         ... 22 more
> Caused by: bitronix.tm.twopc.PhaseException: collected 1 exception(s):
>  [XAOracleDS - bitronix.tm.internal.BitronixXAException(XA_HEURHAZ) -
> unknown heuristic termination, global state of this transaction is unknown -
> guilty: an
>  XAResourceHolderState with uniqueName=XAOracleDS
> XAResource=oracle.jdbc.driver.T4CXAResource@33b503 (ended) with XID a
> Bitronix XID [737072696E672D62746D000
> 000048FAFF26200003CDD : 737072696E672D62746D000000048FAFF2C500003CDF]]
>         at
> bitronix.tm.twopc.AbstractPhaseEngine.executePhase(AbstractPhaseEngine.java:104)
>         at bitronix.tm.twopc.Committer.commit(Committer.java:86)
>         ... 25 more
>
> I can not find any information about it. Can anyone please help me?
>
> Thanks in advance
>
>
>
>
>
>
>
>
>
> --
> View this message in context: http://bitronix-transaction-manager.10986.n7.nabble.com/BitronixHeuristicMixedException-with-DataBase-message-Rolledback-but-Jms-message-is-Sent-with-tp1681.html
> Sent from the Bitronix Transaction Manager mailing list archive at Nabble.com.
>
> ---------------------------------------------------------------------
> To unsubscribe from this list, please visit:
>
>     http://xircles.codehaus.org/manage_email
>
>

---------------------------------------------------------------------
To unsubscribe from this list, please visit:

    http://xircles.codehaus.org/manage_email


Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: BitronixHeuristicMixedException with DataBase message Rolledback but Jms message is Sent with

nandu
Thanks very much for the reply I am always missing only one message as this happens once in a day or two after that batch terminates anyway because of the error.Only a single instance of the batch is running on a single machine nothing in parallel that's the reason hardcoded the server-id.
Do I need to configure something so that my exceptionAnalyzer will show me the correct error as you mentioned?

Currently these are my configuration properties:

VM unique ID: <spring-btm> (thread: main -> bitronix.tm.Configuration.buildServerIdArray(Configuration.java:669))
14:54:07 [DEBUG] starting BitronixTransactionManager using a Configuration with [allowMultipleLrc=false, asynchronous2Pc=false, backgroundRecoveryInterval=1,
 backgroundRecoveryIntervalSeconds=60, currentNodeOnlyRecovery=true, debugZeroResourceTransaction=false, defaultTransactionTimeout=120, disableJmx=false, exc
eptionAnalyzer=null, filterLogStatus=false, forceBatchingEnabled=true, forcedWriteEnabled=true, gracefulShutdownInterval=60, jndiTransactionSynchronizationRe
gistryName=java:comp/TransactionSynchronizationRegistry, jndiUserTransactionName=java:comp/UserTransaction, journal=disk, logPart1Filename=btm1.tlog, logPart2Filename=btm2.tlog, maxLogSizeInMb=2, resourceConfigurationFilename=null, serverId=spring-btm, skipCorruptedLogs=false, warnAboutZeroResourceTransaction=true] (thread: main -> bitronix.tm.BitronixTransactionManager.<init>(BitronixTransactionManager.java:84)


Thanks in advance
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: BitronixHeuristicMixedException with DataBase message Rolledback but Jms message is Sent with

Ludovic Orban-2
The ExceptionAnalyzer is enabled by default, it should work without
any special config setting. Since it relies on reflection to get the
oracle error, it is possible that you're using a driver version in
which Oracle slightly changed the API and the extractor cannot work on
it. I would advise you to check the source code
(http://grepcode.com/file/repo1.maven.org/maven2/org.codehaus.btm/btm/2.1.4/bitronix/tm/utils/DefaultExceptionAnalyzer.java)
and check http://jira.codehaus.org/browse/BTM-98 as this is the
original feature request that ended up as the exception analyzer
mechanism.

From the top of my head, an error that could cause this heuristic is
ORA-24756. It can be caused for instance if Oracle timed out your
transaction because you're approaching the timeout threshold.


The best thing you can do is figure out why you don't get the ORA-***
error code (you might want to decompile your driver to figure out why
the DefaultExceptionAnalyzer cannot extract the error), get that error
code and act upon it. It might be something simple, it might require
involving Oracle support. Whatever the problem is, it seems unlikely
that BTM has anything to do with it.

Good luck.

On Wed, Jan 14, 2015 at 7:15 AM, nandu <[hidden email]> wrote:

> Thanks very much for the reply I am always missing only one message as this
> happens once in a day or two after that batch terminates anyway because of
> the error.Only a single instance of the batch is running on a single machine
> nothing in parallel that's the reason hardcoded the server-id.
> Do I need to configure something so that my exceptionAnalyzer will show me
> the correct error as you mentioned?
>
> Currently these are my configuration properties:
>
> VM unique ID: <spring-btm> (thread: main ->
> bitronix.tm.Configuration.buildServerIdArray(Configuration.java:669))
> 14:54:07 [DEBUG] starting BitronixTransactionManager using a Configuration
> with [allowMultipleLrc=false, asynchronous2Pc=false,
> backgroundRecoveryInterval=1,
>  backgroundRecoveryIntervalSeconds=60, currentNodeOnlyRecovery=true,
> debugZeroResourceTransaction=false, defaultTransactionTimeout=120,
> disableJmx=false, exc
> eptionAnalyzer=null, filterLogStatus=false, forceBatchingEnabled=true,
> forcedWriteEnabled=true, gracefulShutdownInterval=60,
> jndiTransactionSynchronizationRe
> gistryName=java:comp/TransactionSynchronizationRegistry,
> jndiUserTransactionName=java:comp/UserTransaction, journal=disk,
> logPart1Filename=btm1.tlog, logPart2Filename=btm2.tlog, maxLogSizeInMb=2,
> resourceConfigurationFilename=null, serverId=spring-btm,
> skipCorruptedLogs=false, warnAboutZeroResourceTransaction=true] (thread:
> main ->
> bitronix.tm.BitronixTransactionManager.<init>(BitronixTransactionManager.java:84)
>
>
> Thanks in advance
>
>
>
>
> --
> View this message in context: http://bitronix-transaction-manager.10986.n7.nabble.com/BitronixHeuristicMixedException-with-DataBase-message-Rolledback-but-Jms-message-Sent-tp1681p1683.html
> Sent from the Bitronix Transaction Manager mailing list archive at Nabble.com.
>
> ---------------------------------------------------------------------
> To unsubscribe from this list, please visit:
>
>     http://xircles.codehaus.org/manage_email
>
>

---------------------------------------------------------------------
To unsubscribe from this list, please visit:

    http://xircles.codehaus.org/manage_email


Loading...