Problem with AbstractFlushingEventListener and Optimistic Locking

[felixreuthlinger]

Hi,

I have a problem with the AbstractFlushingEventListener from Hibernate, but I don't know if this maybe is a more Hibernate specific problem.

Before you just answer to let me ask at hibernate forums, let me explain the special thing about the application I have this problem with:

I write a simulation for my diploma thesis with the goal to get a lot of entity data manipulation what leads to optimistic locking exceptions. There is no use in trying to avoid these lock, it is my intention to get these optimistic lock exceptions. Every optimistic lock will be caught, counted and handled by the application. So far that is ok and works fine. But sometimes in between some of the optimistic lock exceptions I get this exception:

ERROR 18:46:22,420 [ AbstractFlushingEventListener] ||| Could not synchronize database state with session
org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [de.hsa.simulation.model.trade.Broker#7]
        at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1792)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2435)
        at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2335)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2635)
        at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:115)
        at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279)
        at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
        at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168)
        at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
        at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
        at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027)
        at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365)
        at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:504)
        at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:101)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:263)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:86)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1414)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
        at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
        at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:657)
        at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:243)
        at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:213)
        at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)
WARN  18:46:22,467 [                 arjLoggerI18N] ||| [com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator_2] TwoPhaseCoordinator.beforeCompletion - failed for com.arjuna.ats.i
nternal.jta.resources.arjunacore.SynchronizationImple@1f20365
javax.persistence.OptimisticLockException
        at org.hibernate.ejb.AbstractEntityManagerImpl.wrapStaleStateException(AbstractEntityManagerImpl.java:627)
        at org.hibernate.ejb.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:588)
        at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:513)
        at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:101)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:263)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:86)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1414)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
        at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
        at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:657)
        at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:243)
        at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:213)
        at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:260)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)
Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [de.hsa.simulation.model.trade.Broke
r#7]
        at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1792)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2435)
        at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2335)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2635)
        at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:115)
        at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279)
        at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
        at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168)
        at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
        at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
        at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027)
        at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365)
        at org.hibernate.ejb.AbstractEntityManagerImpl$1.beforeCompletion(AbstractEntityManagerImpl.java:504)
        ... 14 more

The question now is, why does this exception occur and I wonder about how to handle it, as far as it is thrown outside my application (as you can see there are no classes like "de.hsa. ..." mentioned in the stack trace). I've been looking around to find something about this AbstractFlushingEventListener, but without result. Everything about this AbstractFlushingEventListener to find is like for JBoss AS 4.x.x or some older Hibernate issues.

I also played around with hibernate.flushmode configuration, but also without results. I tried AUTO, COMMIT and ALWAYS, but with every of these settings this exception will still occur. And I've splitted up the code doing the manipulations into a lot of single transactions. This exception starts occurring when I get about 20-50 transaction commits per second with some optimistic locks.

Any advice about why this exception may occur and how to handle/prevent it would be very helpful.

If you want to see some entity or programm code causing these lines, I can post some more of these too, but there is nothing special about the entities. I just use Integer/Date @Version fields for optimistic locking and at the moment there are no @OneToMany relations, just some @ManyToOne.

Thanks for any advice :-),

Felix

[smarlow]

Felix,

Judging by the details in the exception call stack below, you are not using the latest Hibernate trunk bits.  If you were, the line numbers would be different and more importantly, you would have some recent improvements that were checked in.  I put in a pessimistic lock exception fix recently that was similar to what you are reporting.

After switching to the latest Hibernate bits, you should hopefully see OptimisticLockException coming through to your application (for the error that you are experiencing).

To build the latest source, you will need some tools such as Java JDK 5.x + 6.x, Maven, Subversion.  You should find some guidance on Hibernate.org.

In answer to your questions:

1.  Any advice about why this exception may occur and how to handle and prevent it?

Answer:  Database optimistic locking is a technique where your application code will assume that it can always read/write any database data.  Without fear that other user requests (think in database transaction terms here) will contend for the same data.  This is done, knowing that other user requests can actually contend for the same database table data.  We are going to optimisticly assume other users are not changing the database data that our transaction has already read, however, at the end of our database transaction, we will check if this has happended (just in case).  The alternative is using pessimistic locking, where you lock the database data early in the database transaction, to ensure that your database transaction will succeed.

The error below, is informing you that another user request (database transaction) has already modified the database data (as detected by the Hibernate optimistic lock checking).

2.  If you want to see some entity or programming code causing these lines, I can post some more of these too, but there is nothing special about the entities. I just use Integer/Date @Version fields for optimistic locking and at the moment there are no @OneToMany relations, just some @ManyToOne.

Answer: If you pull down the latest Hibernate trunk source code and help test it.  You can also create some unit tests for any failures that you run into.  Just to be clear, the failure below is not a bug, but if you don't get a OptimisticLockException (with the Hibernate trunk (latest)) sources, that is a bug.

The unit tests can be attached to Jira bug reports that describe what is wrong and why.  User questions do not go into the bug reports, only actual bugs. As a bonus, you can also submit code changes to the Hibernate code (Subversion will generate the patch file for you and then attach that to the bug reoprt as well).

Its really up to you and how passionately you want to be about working with Hibernate.  Although, since you are asking here, I really must insist that you jump in and get involved with Hibernate development.  :-)

Regards,

Scott

[smarlow]

Felix,

Also start getting familar with the AS trunk source.  Start looking at hibernate.org and http://www.jboss.org/jbossas/.  Let me know your interest and I will post more links to help get you started.

Scott

[felixreuthlinger]

Hey Scott,

thank you, for this fast reponse!

For the version of hibernate I'm using, it's the one from JBoss AS 5.1.0 GA, I've not been in to checkin out some later trunk versions.

But you mentioned that I should get the optimistic lock exception thrown to my application, that is one thing I still have to check. It is quite hard to identify if there is an exception also throw to the application because I get loads of them. And this exception that is logged by the flushing listener, maybe it's thrown to the application too.

But if this is it, I think it's very confusing to see the flushing listener logging the output for this exception. Normally I would expect that only the application logic receiving this exception would also log it.

The usage of pessimistic locking is not really a good possibllity in my application, it would slow everything a lot. And I want to produce some optimistic lock exceptions for an later evaluation of clustering with and without some different, clustered caches for entities.

I will look into some newer hibernate version and let you know if there's some change that solves my problem :-)

Regards,

Felix