Marko Bekhta (
https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%...
) *created* an issue
Hibernate Search (
https://hibernate.atlassian.net/browse/HSEARCH?atlOrigin=eyJpIjoiOGNkMDcy...
) / Bug (
https://hibernate.atlassian.net/browse/HSEARCH-4749?atlOrigin=eyJpIjoiOGN...
) HSEARCH-4749 (
https://hibernate.atlassian.net/browse/HSEARCH-4749?atlOrigin=eyJpIjoiOGN...
) MSSQL cannot acuire locks properly on outbox event table (
https://hibernate.atlassian.net/browse/HSEARCH-4749?atlOrigin=eyJpIjoiOGN...
)
Issue Type: Bug Assignee: Marko Bekhta (
https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%...
) Created: 10/Nov/2022 11:34 AM Priority: Major Reporter: Marko Bekhta (
https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%...
)
After the switch to UUIDs as IDs of outbox events ( HSEARCH-4678 (
https://hibernate.atlassian.net/browse/HSEARCH-4678 ) ), MSSQL fails to acquire locks per
row, and as a result, only one batch is successful while others are set for retry:
20:29:19,608 (main) DEBUG OutboxPollingEventProcessor:208 - HSEARCH850006: Stopping outbox
event processor 'Outbox event processor'
20:29:19,608 (main) INFO AgentPersister:60 - Agent '#3 - Outbox event processor':
leaving cluster
20:29:19,609 (Hibernate Search - Outbox event processor - 0) INFO
DefaultOutboxEventFinder:68 - Hibernate Search - Outbox event processor -
0 : [c61469e5-b9d6-4ae0-bf61-6bdd30efa778, fa80a59e-9e6e-486e-8036-4bf300c3407b,
53049774-a31f-4805-a1eb-19ca39fd6f71, 0d04e668-1254-4b6f-8087-2269d60763b2,
84252f01-8565-418f-9390-0ca39af5c19d]
20:29:19,609 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:52 -
Agent '#4 - Outbox event processor': registering
20:29:19,612 (main) INFO pooling:550 - HHH10001008: Cleaning up connection pool
[jdbc:sqlserver://localhost:1433;databaseName=tempdb]
20:29:19,613 (Hibernate Search - Outbox event processor - 0) INFO
OutboxPollingEventProcessorClusterLink:132 - Agent '#4 - Outbox event processor':
the persisted shard assignment (null) does not match the target. Target assignment: shard
1 (total 2). Cluster: [2, 4].
20:29:19,615 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:81 -
Agent '#4 - Outbox event processor': waiting for cluster changes. Shard
assignment: shard 1 (total 2). Cluster: [2, 4]
20:29:19,638 (Hibernate Search - Outbox event processor - 0) INFO
OutboxPollingEventProcessorClusterLink:132 - Agent '#2 - Outbox event processor':
the persisted shard assignment (shard 0 (total 1)) does not match the target. Target
assignment: shard 0 (total 2). Cluster: [2, 4].
20:29:19,639 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:81 -
Agent '#2 - Outbox event processor': waiting for cluster changes. Shard
assignment: shard 0 (total 2). Cluster: [2, 4]
20:29:19,642 (Hibernate Search - Outbox event processor - 0) INFO
OutboxPollingEventProcessorClusterLink:177 - Agent '#4 - Outbox event processor':
assigning to shard 1 (total 2)
20:29:19,645 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:93 -
Agent '#4 - Outbox event processor': running. Shard assignment: shard 1 (total 2).
Cluster: [2, 4]
20:29:19,650 (Hibernate Search - Outbox event processor - 0) INFO
OutboxPollingEventProcessorClusterLink:177 - Agent '#2 - Outbox event processor':
assigning to shard 0 (total 2)
20:29:19,652 (Hibernate Search - Outbox event processor - 0) INFO
DefaultOutboxEventFinder:68 - Hibernate Search - Outbox event processor -
0 : [fec8d219-88f5-4c02-ba4f-41d0af76f4b3, e8242905-fa19-4611-b78d-8a4a1459cb96,
5bf374a4-2401-45af-b985-7af9fe4bea43, c711050d-d21d-46c9-91cb-e3f0dd4bd326,
91d6a778-8d8c-444f-a560-7068bc8feea7]
20:29:19,653 (Hibernate Search - Outbox event processor - 0) INFO AgentPersister:93 -
Agent '#2 - Outbox event processor': running. Shard assignment: shard 0 (total 2).
Cluster: [2, 4]
20:29:19,658 (Hibernate Search - Outbox event processor - 0) INFO
DefaultOutboxEventFinder:68 - Hibernate Search - Outbox event processor -
0 : [927fe2d9-950c-453b-a785-ac02cd4676a1, 16079de3-b77e-4edf-9967-4f630edceab7,
c495ec0b-561b-423d-92f9-9b295ccb354e, 10b4ac28-c877-4035-8c22-4b608bf93c56,
46d77975-cf34-475e-a0c9-40b5495dcf11]
20:29:20,844 (Hibernate Search - Outbox event processor - 0) WARN SqlExceptionHelper:137
- SQL Error: 1205, SQLState: 40001
20:29:20,845 (Hibernate Search - Outbox event processor - 0) ERROR SqlExceptionHelper:142
- Transaction (Process ID 52) was deadlocked on lock resources with another process and
has been chosen as the deadlock victim. Rerun the transaction.
20:29:20,845 (Hibernate Search - Outbox event processor - 0) INFO AbstractBatchImpl:213 -
HHH000010: On release of batch it still contained JDBC statements
20:29:20,847 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:31 -
HSEARCH000058: Exception occurred javax.persistence.OptimisticLockException:
org.hibernate.exception.LockAcquisitionException: could not execute statement
Failing operation:
Executing task 'Outbox event processor'
javax.persistence.OptimisticLockException:
org.hibernate.exception.LockAcquisitionException: could not execute statement
at
org.hibernate.internal.ExceptionConverterImpl.wrapLockException(ExceptionConverterImpl.java:277)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:98)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:188)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1411)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:489)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3303)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2438)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:449)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.search.mapper.orm.common.spi.TransactionHelper.commit(TransactionHelper.java:102)
~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.mapper.orm.common.spi.TransactionHelper.inTransaction(TransactionHelper.java:60)
~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:286)
~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199)
~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement
at
org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:120)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:37)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:200)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3698)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3987)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:123)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at java.util.LinkedHashMap.forEach(LinkedHashMap.java:721) ~[?:?]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:344)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1407)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
... 18 more
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 52)
was deadlocked on lock resources with another process and has been chosen as the deadlock
victim. Rerun the transaction.
at
com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:262)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1632)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:602)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:524)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7418)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:3272)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:247)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:222)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.executeUpdate(SQLServerPreparedStatement.java:473)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:197)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3698)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3987)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:123)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at java.util.LinkedHashMap.forEach(LinkedHashMap.java:721) ~[?:?]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:344)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1407)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
... 18 more
20:29:20,851 (Hibernate Search - Outbox event processor - 0) INFO
DefaultOutboxEventFinder:68 - Hibernate Search - Outbox event processor -
0 : [927fe2d9-950c-453b-a785-ac02cd4676a1, 16079de3-b77e-4edf-9967-4f630edceab7,
c495ec0b-561b-423d-92f9-9b295ccb354e, 10b4ac28-c877-4035-8c22-4b608bf93c56,
46d77975-cf34-475e-a0c9-40b5495dcf11]
20:29:20,855 (Hibernate Search - Outbox event processor - 0) INFO
DefaultOutboxEventFinder:68 - Hibernate Search - Outbox event processor -
0 : [b74ae6ea-309e-463d-a242-440d9aaa7635, 8252e81b-575b-4804-a162-05f3fe710d7c,
82fde0f9-3168-45ac-87d7-6d731bc68b79, c7ced801-8122-41a9-aca6-505a516caf24,
834fbe69-8ede-4a8a-a841-f9eeef45d597]
20:29:21,470 (Hibernate Search - Outbox event processor - 0) WARN SqlExceptionHelper:137
- SQL Error: 1205, SQLState: 40001
20:29:21,470 (Hibernate Search - Outbox event processor - 0) ERROR SqlExceptionHelper:142
- Transaction (Process ID 54) was deadlocked on lock resources with another process and
has been chosen as the deadlock victim. Rerun the transaction.
20:29:21,470 (Hibernate Search - Outbox event processor - 0) INFO AbstractBatchImpl:213 -
HHH000010: On release of batch it still contained JDBC statements
20:29:21,472 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:31 -
HSEARCH000058: Exception occurred javax.persistence.OptimisticLockException:
org.hibernate.exception.LockAcquisitionException: could not execute statement
Failing operation:
Executing task 'Outbox event processor'
javax.persistence.OptimisticLockException:
org.hibernate.exception.LockAcquisitionException: could not execute statement
at
org.hibernate.internal.ExceptionConverterImpl.wrapLockException(ExceptionConverterImpl.java:277)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:98)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:188)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1411)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:489)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3303)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2438)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:449)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.search.mapper.orm.common.spi.TransactionHelper.commit(TransactionHelper.java:102)
~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.mapper.orm.common.spi.TransactionHelper.inTransaction(TransactionHelper.java:60)
~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:286)
~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199)
~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement
at
org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:120)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:37)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:200)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3698)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3987)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:123)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at java.util.LinkedHashMap.forEach(LinkedHashMap.java:721) ~[?:?]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:344)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1407)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
... 18 more
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 54)
was deadlocked on lock resources with another process and has been chosen as the deadlock
victim. Rerun the transaction.
at
com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:262)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1632)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:602)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:524)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7418)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:3272)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:247)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:222)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.executeUpdate(SQLServerPreparedStatement.java:473)
~[mssql-jdbc-9.2.1.jre11.jar:?]
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:197)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3698)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3987)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:123)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at java.util.LinkedHashMap.forEach(LinkedHashMap.java:721) ~[?:?]
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:344)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1407)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
... 18 more
20:29:21,476 (Hibernate Search - Outbox event processor - 0) INFO
DefaultOutboxEventFinder:68 - Hibernate Search - Outbox event processor -
0 : [b74ae6ea-309e-463d-a242-440d9aaa7635, 8252e81b-575b-4804-a162-05f3fe710d7c,
82fde0f9-3168-45ac-87d7-6d731bc68b79, c7ced801-8122-41a9-aca6-505a516caf24,
834fbe69-8ede-4a8a-a841-f9eeef45d597]
20:29:21,477 (Hibernate Search - Outbox event processor - 0) INFO
DefaultOutboxEventFinder:68 - Hibernate Search - Outbox event processor -
0 : [bc9eabd1-12de-4085-854a-a4c6de7991b2, 0fb3f934-0022-4aaa-9ea8-4456135b984e,
9b28f25a-ab8d-4874-9c8e-8713529b6ffc, 5f0ed577-5ab0-4150-993b-595ff2e02c0e,
bdd7ecd3-3b85-4c01-b139-8abf1e5a371e]
20:29:21,783 (Hibernate Search - Outbox event processor - 0) WARN SqlExceptionHelper:137
- SQL Error: 1205, SQLState: 40001
20:29:21,783 (Hibernate Search - Outbox event processor - 0) ERROR SqlExceptionHelper:142
- Transaction (Process ID 54) was deadlocked on lock resources with another process and
has been chosen as the deadlock victim. Rerun the transaction.
20:29:21,783 (Hibernate Search - Outbox event processor - 0) INFO AbstractBatchImpl:213 -
HHH000010: On release of batch it still contained JDBC statements
20:29:21,784 (Hibernate Search - Outbox event processor - 0) ERROR LogFailureHandler:31 -
HSEARCH000058: Exception occurred javax.persistence.OptimisticLockException:
org.hibernate.exception.LockAcquisitionException: could not execute statement
Failing operation:
Executing task 'Outbox event processor'
javax.persistence.OptimisticLockException:
org.hibernate.exception.LockAcquisitionException: could not execute statement
at
org.hibernate.internal.ExceptionConverterImpl.wrapLockException(ExceptionConverterImpl.java:277)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:98)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:188)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1411)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:489)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3303)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2438)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:449)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
at
org.hibernate.search.mapper.orm.common.spi.TransactionHelper.commit(TransactionHelper.java:102)
~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.mapper.orm.common.spi.TransactionHelper.inTransaction(TransactionHelper.java:60)
~[hibernate-search-mapper-orm-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.mapper.orm.coordination.outboxpolling.event.impl.OutboxPollingEventProcessor$Worker.work(OutboxPollingEventProcessor.java:286)
~[hibernate-search-mapper-orm-coordination-outbox-polling-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at
org.hibernate.search.engine.backend.orchestration.spi.SingletonTask$RunnableWrapper.run(SingletonTask.java:199)
~[hibernate-search-engine-6.2.0-SNAPSHOT.jar:6.2.0-SNAPSHOT]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
~[?:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement
(
https://hibernate.atlassian.net/browse/HSEARCH-4749#add-comment?atlOrigin...
) Add Comment (
https://hibernate.atlassian.net/browse/HSEARCH-4749#add-comment?atlOrigin...
)
Get Jira notifications on your phone! Download the Jira Cloud app for Android (
https://play.google.com/store/apps/details?id=com.atlassian.android.jira....
) or iOS (
https://itunes.apple.com/app/apple-store/id1006972087?pt=696495&ct=Em...
) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100210- sha1:583150f )