[JIRA] (HV-1928) Bad validator performance when adding obsolete @Validated to Java value objects
by Peter Walser (JIRA)
Peter Walser ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... ) *commented* on HV-1928 ( https://hibernate.atlassian.net/browse/HV-1928?atlOrigin=eyJpIjoiMTA4MTA4... )
Re: Bad validator performance when adding obsolete @Validated to Java value objects ( https://hibernate.atlassian.net/browse/HV-1928?atlOrigin=eyJpIjoiMTA4MTA4... )
When I wrap the values into value objects (with @Valid), the validation runs very fast (although it supposedly does the same: recurse into values with @Valid and validate with @NotNull and @Min ):
public class Item {
private Id id;
private Quantity quantity;
public @Valid Id getId() { return id; }
public void setId(Id id) { this.id = id; }
public @Valid Quantity getQuantity() { return quantity; }
public void setQuantity(Quantity quantity) { this.quantity = quantity; }
public static class Id {
private Long id;
public @NotNull Long getId() { return id; }
public void setId(Long id) { this.id = id; }
}
public static class Quantity {
private int quantity;
public @Min(1) int getQuantity() { return quantity; }
public void setQuantity(int quantity) { this.quantity = quantity; }
}
}
0 items, avg. validation time: 49.520402 ms
1 items, avg. validation time: 50.609528 ms
2 items, avg. validation time: 50.88673 ms
5 items, avg. validation time: 50.236684 ms
10 items, avg. validation time: 49.789304 ms
20 items, avg. validation time: 48.713483 ms
50 items, avg. validation time: 50.069192 ms
100 items, avg. validation time: 50.027649 ms
200 items, avg. validation time: 49.037075 ms
500 items, avg. validation time: 50.690123 ms
1000 items, avg. validation time: 50.057061 ms
2500 items, avg. validation time: 49.99966 ms
5000 items, avg. validation time: 48.518808 ms
7500 items, avg. validation time: 50.0492 ms
10000 items, avg. validation time: 50.01165 ms
20000 items, avg. validation time: 48.984054 ms
30000 items, avg. validation time: 51.152249 ms
40000 items, avg. validation time: 50.320894 ms
50000 items, avg. validation time: 50.039272 ms
( https://hibernate.atlassian.net/browse/HV-1928#add-comment?atlOrigin=eyJp... ) Add Comment ( https://hibernate.atlassian.net/browse/HV-1928#add-comment?atlOrigin=eyJp... )
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=EmailN... ) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100210- sha1:583150f )
1 year, 10 months
[JIRA] (HV-1928) Bad validator performance when adding obsolete @Validated to Java value objects
by Peter Walser (JIRA)
Peter Walser ( https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%... ) *commented* on HV-1928 ( https://hibernate.atlassian.net/browse/HV-1928?atlOrigin=eyJpIjoiNjNmZDQz... )
Re: Bad validator performance when adding obsolete @Validated to Java value objects ( https://hibernate.atlassian.net/browse/HV-1928?atlOrigin=eyJpIjoiNjNmZDQz... )
The validation time also *grows exponentially* with the number of items:
0 items, avg. validation time: 0.078653 ms
1 items, avg. validation time: 0.233635 ms
2 items, avg. validation time: 0.277518 ms
5 items, avg. validation time: 0.442096 ms
10 items, avg. validation time: 0.386543 ms
20 items, avg. validation time: 0.352659 ms
50 items, avg. validation time: 0.69204 ms
100 items, avg. validation time: 1.090923 ms
200 items, avg. validation time: 2.762619 ms
500 items, avg. validation time: 7.474321 ms
1000 items, avg. validation time: 27.675976 ms
2500 items, avg. validation time: 184.583688 ms
5000 items, avg. validation time: 624.382551 ms
7500 items, avg. validation time: 1262.320178 ms
10000 items, avg. validation time: 2125.455512 ms
20000 items, avg. validation time: 8322.531352 ms
30000 items, avg. validation time: 19281.462 ms
( https://hibernate.atlassian.net/browse/HV-1928#add-comment?atlOrigin=eyJp... ) Add Comment ( https://hibernate.atlassian.net/browse/HV-1928#add-comment?atlOrigin=eyJp... )
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=EmailN... ) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100210- sha1:583150f )
1 year, 10 months
[JIRA] (HSEARCH-4749) MSSQL cannot acuire locks properly on outbox event table
by Marko Bekhta (JIRA)
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=EmailN... ) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100210- sha1:583150f )
1 year, 10 months
