Issues with JBoss 4.2.2 XA Resources and Postgres 8.2.5

[getkarthik]

Hi

We are planning to migrate from JBoss 4.0.5 to JBoss 4.2.2. Until now our application was using Local Transactions even while persisting data into Multiple Databases [currently all databases residing on the same machine]. We are using postgres 8.2.5 as our database.

With the 4.2.2 version of JBoss local transactions were failing and we migrated to XA Datasources [and which I believe is the right way] and involve in 2PC. But we frequently encounter the problem of HeuristicMixedException with XA Transactions. The interesting thing to note was only a particualr DataBase was failing and we were using Native Query API from EJB3.0 for this particular DB. All other database are accessed via the standard EntityManager persist and merge operations. I am not sure if we shouldnt be calling flush() and executeUpdate() after every persist and NativeQuery update operations respectively on the EntityManager. I conducted tests changing the FlushModeType and calling EnityManager.joinTransaction() but nothing stops this failure.

Can anyone please advice.


Below is the exception:


org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - java.lang.RuntimeException: javax.transaction.HeuristicMixedException
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aspects.tx.TxPolicy.handleEndTransactionException(TxPolicy.java:198)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aspects.tx.TxPolicy.endTransaction(TxPolicy.java:184)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:87)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aspects.tx.TxInterceptor$RequiresNew.invoke(TxInterceptor.java:253)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)


org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at java.lang.Thread.run(Thread.java:595)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - Caused by: javax.transaction.HeuristicMixedException
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1397)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - at org.jboss.aspects.tx.TxPolicy.endTransaction(TxPolicy.java:175)
org.jboss.logging.util.LoggerStream (LoggerStream.java:152) - ... 86 more

[adinn]

Can anyone please advise.

Below is the exception:

The exception doesn't really say much about why it went wrong. Look for other info in the server log indicating why the outcome is heuristic. If necessary switch on debug trace in the transaction code to up the amount of info in the log.

What is the particular DB which is failing?

[getkarthik]

Hi Adinn,
Sorry for the late reply. As an immediate fix we just made it use the LastResourceCommitOptimization to true and use local transations which I know is a very bad option.

I am using 3 Databases[all postgres8.2.5] and in 95% of the cases it happens when I perform operation on all 3 databases. Rarely it happens with 2 database based 2PC.

I couldnt get any more details on the exception stack trace other than that it complains about the outcome of the 2PC.


Can you advice?

Below is the pre-exception warning.

[http-0.0.0.0-8080-11] com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord (XAResourceRecord.java:275) - [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] XAResourceRecord.prepare - prepare failed with exception XAException.XAER_RMERR
[http-0.0.0.0-8080-11] com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord (XAResourceRecord.java:275) - [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] XAResourceRecord.prepare - prepare failed with exception XAException.XAER_RMERR
[http-0.0.0.0-8080-11] com.arjuna.ats.arjuna.coordinator.BasicAction (BasicAction.java:2959) - [com.arjuna.ats.arjuna.coordinator.BasicAction_50] - Prepare phase of action -53e6fdcc:95a5:489e16ca:3bec received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD
[http-0.0.0.0-8080-11] com.arjuna.ats.arjuna.coordinator.BasicAction (BasicAction.java:2959) - [com.arjuna.ats.arjuna.coordinator.BasicAction_50] - Prepare phase of action -53e6fdcc:95a5:489e16ca:3bec received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD
[http-0.0.0.0-8080-11] com.arjuna.ats.arjuna.coordinator.BasicAction (BasicAction.java:1787) - [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id -53e6fdcc:95a5:489e16ca:3bec failed.
[http-0.0.0.0-8080-11] com.arjuna.ats.arjuna.coordinator.BasicAction (BasicAction.java:1787) - [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id -53e6fdcc:95a5:489e16ca:3bec failed.
[http-0.0.0.0-8080-11] com.arjuna.ats.arjuna.coordinator.BasicAction (BasicAction.java:1795) - [com.arjuna.ats.arjuna.coordinator.BasicAction_37] - Received heuristic: TwoPhaseOutcome.HEURISTIC_HAZARD .
[http-0.0.0.0-8080-11] com.arjuna.ats.arjuna.coordinator.BasicAction (BasicAction.java:1795) - [com.arjuna.ats.arjuna.coordinator.BasicAction_37] - Received heuristic: TwoPhaseOutcome.HEURISTIC_HAZARD .
[http-0.0.0.0-8080-11] com.arjuna.ats.arjuna.coordinator.BasicAction (BasicAction.java:1801) - [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting
[http-0.0.0.0-8080-11] com.arjuna.ats.arjuna.coordinator.BasicAction (BasicAction.java:1801) - [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting

[jhalliday]

What do the logs from postgres show?

[getkarthik]

Hi,
I think I got the possible cause of this issue, I ran my test again and this is the log from postgresql

ERROR: maximum number of prepared transactions reached
HINT: Increase max_prepared_transactions (currently 5).
STATEMENT: PREPARE TRANSACTION '131075_MS0tNTNlNmZkY2M6OTIyNjo0ODllMzY0ZDoxNzIyOA==_LTUzZTZmZGNjOjkyMjY6NDg5ZTM2NGQ6MTcyNWE='
I will update this parameter required for the 2PC and test it again.

[getkarthik]

Hi adinn & jhalliday
I increased this attribute and it started working fine. Thanks for pointing to troubleshoot in the right direction.

--Thanks