|
Hi All,
(Please note that I'm filing this bug initially without a test case (will try to create one once if I have some free time), just trying to convey this misbehavior that might be fixed in the forthcoming 4.3.0.)
STEPS TO REPRODUCE:
0. Create a .war application (include hibernate-core and hibernate-envers version 4.3.0.Beta4)
1. Use plain Hibernate, no JPA (hibernate.cfg.xml and *.hbm.xml mappings)
2. Use an entity that is @Audited
3. Configure Hibernate to use JTA in hibernate.cfg.xml. The relevant settings are:
<property name="hibernate.current_session_context_class">jta</property>
<property name="hibernate.transaction.factory_class">org.hibernate.engine.transaction.internal.jta.JtaTransactionFactory</property>
<property name="hibernate.transaction.jta.platform">org.hibernate.engine.transaction.jta.platform.internal.JBossAppServerJtaPlatform</property>
4. Add simple code saving new audited entity like below:
javax.transaction.UserTransaction ut = <get it from container>;
ut.begin();
sessionFactory.getCurrentSession().save(new AuditedEntity());
ut.commit();
At the commit time, there will be an exception as Envers cannot save audit information claiming Hibernate transaction is not active:
Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1177)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:167)
at com.rolotex.common.transaction.TransactionHelper.commitTransaction(TransactionHelper.java:49) [common-trunk.jar:]
... 31 more
Caused by: org.hibernate.envers.exception.AuditException: Unable to create revision because of non-active transaction
at org.hibernate.envers.event.spi.BaseEnversEventListener.checkIfTransactionInProgress(BaseEnversEventListener.java:146) [hibernate-envers-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.envers.event.spi.EnversPostUpdateEventListenerImpl.onPostUpdate(EnversPostUpdateEventListenerImpl.java:51) [hibernate-envers-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.action.internal.EntityUpdateAction.postUpdate(EntityUpdateAction.java:265) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:223) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:377) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:369) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:287) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:340) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:52) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1235) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:405) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorImpl.beforeCompletion(SynchronizationCallbackCoordinatorImpl.java:113) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:53) [hibernate-core-4.3.0.Beta4.jar:4.3.0.Beta4]
at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:273)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:93)
at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1165)
... 35 more
The check in BaseEnversEventListener is:
protected void checkIfTransactionInProgress(SessionImplementor session) {
if ( !session.isTransactionInProgress() ) {
throw new AuditException( "Unable to create revision because of non-active transaction" );
}
}
WORKAROUND:
The workaround we use is to call .begin() on Hibernate transaction after calling .begin() on UserTransaction:
javax.transaction.UserTransaction ut = <get it from container>;
ut.begin();
Session session = sessionFactory.getCurrentSession();
org.hibernate.Transaction transaction = session.getTransaction();
transaction.begin();
sessionFactory.getCurrentSession().save(new AuditedEntity());
ut.commit();
PROBLEM ANALYSIS:
Proposed fix is to change AbstractTransactionImpl.localStatus to LocalStatus.ACTIVE when joining JTA transaction, as
session.isTransactionInProgress() check eventually delegates to TransactionCoordinatorImpl method:
public boolean isTransactionInProgress() {
return open && getTransaction().isActive() && getTransaction().getJoinStatus() == JoinStatus.JOINED;
}
and JtaTransaction.isActive() method checks localStatus first:
public boolean isActive() throws HibernateException {
if ( getLocalStatus() != LocalStatus.ACTIVE ) {
return false;
}
final int status;
try {
status = userTransaction.getStatus();
}
catch ( SystemException se ) {
throw new TransactionException( "Could not determine transaction status: ", se );
}
return JtaStatusHelper.isActive( status );
}
The problem is that AbstractTransactionImpl class has the following field with the default set to LocalStatus.NOT_ACTIVE:
private LocalStatus localStatus = LocalStatus.NOT_ACTIVE;
This field is only changed when begin(), commit(), rollback() methods are called on org.hibernate.Transaction.
When Hibernate joins JTA transaction in the test code above, this field is NOT changed (that's the bug).
PROPOSED FIX:
Although I'm not familiar with the Hibernate codebase, perhaps the fix is to set localStatus to LocalStatus.ACTIVE in JtaTransaction constructor IF the JTA transaction is already in progress. However, I guess it does not cover the case when UserTransaction is started after this constructor is invoked (not sure if such scenario is possible, though). Also, it may contradict localStatus meaning that seems to be designation of begin(), commit(), rollback() method calls on org.hibernate.Transaction.
Thus, the other alternative is to remove "getLocalStatus() != LocalStatus.ACTIVE" check from JtaTransaction.isActive() method and delegate just to UserTransaction to check the state. Note that Transaction.isActive() JavaDoc says "Answers on a best effort basis", thus it should be a valid approach, I believe. Also, similar CMTTransaction does not perform getLocalStatus() check.
NOTE: I found a report of a similar error with Hibernate + Envers + JTA, and one of the comments is that using JPA instead of plain Hibernate resolves the issue.I have had no chance to check if really using JPA workarounds the issue (see https://community.jboss.org/thread/168087?start=0&tstart=0&_sscc=t).
|
Major
