Hibernate Search encountered LockAcquisitionException trying to load a collection during a commit.

My thread updated a database table. After updating my object via hibernate I called commit which resulted in hibernate search synchronizing our lucene indexes with the database. This synchronization encountered a deadlock which resulted in loss of original update.

The problem as I understand is:
This exception killed/rolled back our transaction and the exception was completely consumed by Hibernate during JDBCTransaction.commit
without re-throwing it. LockAcquisitionException in all cases will end up rolling back the current transaction, but in this case, because the exception was consumed by notifyLocalSynchsBeforeTransactionCompletion method, the thread continued and commit failed without our code ever knowing about it.

Does anybody know why this method notifyLocalSynchsBeforeTransactionCompletion is consuming all exceptions?

Here is the stack trace:

11:00:05.749 ERROR [cerecalculate-2] org.hibernate.transaction.JDBCTransaction (line 277 ) exception calling user Synchronization
org.hibernate.exception.LockAcquisitionException: could not initialize a collection: [com.oc.ecc.model.Person.addresses#587035cf-7b75-4281-b745-28d98eea4aa5]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:105) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.loader.Loader.loadCollection(Loader.java:2026) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.loader.collection.CollectionLoader.initialize(CollectionLoader.java:59) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:587) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:83) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1744) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.collection.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:366) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.collection.AbstractPersistentCollection.read(AbstractPersistentCollection.java:108) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.collection.PersistentSet.iterator(PersistentSet.java:186) ~[hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.search.engine.DocumentBuilderIndexedEntity.buildDocumentFields(DocumentBuilderIndexedEntity.java:436) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.engine.DocumentBuilderIndexedEntity.getDocument(DocumentBuilderIndexedEntity.java:380) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.engine.DocumentBuilderIndexedEntity.createAddWork(DocumentBuilderIndexedEntity.java:328) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.engine.DocumentBuilderIndexedEntity.addWorkToQueue(DocumentBuilderIndexedEntity.java:312) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.engine.DocumentBuilderContainedEntity.processContainedInValue(DocumentBuilderContainedEntity.java:634) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.engine.DocumentBuilderContainedEntity.processContainedIn(DocumentBuilderContainedEntity.java:624) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.engine.DocumentBuilderContainedEntity.addWorkToQueue(DocumentBuilderContainedEntity.java:564) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.engine.DocumentBuilderIndexedEntity.addWorkToQueue(DocumentBuilderIndexedEntity.java:323) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.backend.impl.BatchedQueueingProcessor.addWorkToBuilderQueue(BatchedQueueingProcessor.java:153) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.backend.impl.BatchedQueueingProcessor.processWorkByLayer(BatchedQueueingProcessor.java:140) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.backend.impl.BatchedQueueingProcessor.prepareWorks(BatchedQueueingProcessor.java:128) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization.beforeCompletion(PostTransactionWorkQueueSynchronization.java:47) ~[hibernate-search-3.1.1.GA.jar:3.1.1.GA]
at org.hibernate.transaction.JDBCTransaction.notifyLocalSynchsBeforeTransactionCompletion(JDBCTransaction.java:274) [hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:140) [hibernate-core-3.3.2.GA.jar:3.3.2.GA]
at com.oc.ecc.tx.impl.TransactionManagerImpl.endTransaction(TransactionManagerImpl.java:98) [ecc-lib-4.0.13.5.jar:4.0.13.5]
at $TransactionManager_1321a1a197d.endTransaction($TransactionManager_1321a1a197d.java) [tapestry-framework-4.1.6m.jar:na]
at $TransactionManager_1321a1a197e.endTransaction($TransactionManager_1321a1a197e.java) [tapestry-framework-4.1.6m.jar:na]
at com.oc.ecc.job.DeviceRecalculate.executeJob(DeviceRecalculate.java:35) [ecc-lib-4.0.13.5.jar:4.0.13.5]
at com.oc.ecc.job.BaseAsyncJob.call(BaseAsyncJob.java:320) [ecc-lib-4.0.13.5.jar:4.0.13.5]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [na:1.6.0_24]
at java.util.concurrent.FutureTask.run(FutureTask.java:138) [na:1.6.0_24]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) [na:1.6.0_24]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) [na:1.6.0_24]
at com.oc.ecc.job.impl.AsyncJobExecutorImpl$WrappedRunnableScheduledFuture.run(AsyncJobExecutorImpl.java:109) [ecc-lib-4.0.13.5.jar:4.0.13.5]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [na:1.6.0_24]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [na:1.6.0_24]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_24]


I am using SQLServer database. This exception was encountered using hibernate core version 3.3.2.GA and hibernate-search version 3.1.1.GA. I later downloaded hibernate core 3.6.7.Final but the behavior there is the same.

Hi,
that's indeed a nasty scenario, but I don't think we can change notifyLocalSynchsBeforeTransactionCompletion for the Hibernate 3.x series.

Could you verify if this problem affects Hibernate Core 4.x and Hibernate Search 4.x too ?
For these breaking some APIs would be fine, but we're already in CR phase so I'd need to discuss this.