We're updating the issue view to help you get more done. 

Avoid random failures in TestRunnerStandalone.runPerformanceTest

Description

The failures happen randomly and are caused by concurrency issues:

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 javax.persistence.PessimisticLockException: could not execute statement at org.hibernate.internal.ExceptionConverterImpl.wrapLockException(ExceptionConverterImpl.java:249) at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:103) at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:157) at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:164) at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1443) at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:493) at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3207) at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2413) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:467) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:156) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231) at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68) at org.hibernate.search.test.performance.task.AbstractTask.run(AbstractTask.java:53) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) Caused by: org.hibernate.PessimisticLockException: could not execute statement at org.hibernate.dialect.H2Dialect$3.convert(H2Dialect.java:352) at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:178) at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3198) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3077) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3457) at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:145) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:589) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:463) at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337) at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1437) at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:493) at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3207) at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2413) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:467) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:156) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231) at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68) at org.hibernate.search.test.performance.task.AbstractTask.run(AbstractTask.java:53) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) Caused by: org.h2.jdbc.JdbcSQLException: Timeout trying to lock table ; SQL statement: update book set publicationDate=?, rating=?, summary=?, title=?, totalSold=? where id=? [50200-178] at org.h2.message.DbException.getJdbcSQLException(DbException.java:344) at org.h2.message.DbException.get(DbException.java:167) at org.h2.command.Command.filterConcurrentUpdate(Command.java:301) at org.h2.command.Command.executeUpdate(Command.java:256) at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:158) at org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:144) at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175) at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3198) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3077) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3457) at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:145) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:589) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:463) at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337) at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1437) at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:493) at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3207) at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2413) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:467) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:156) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231) at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68) at org.hibernate.search.test.performance.task.AbstractTask.run(AbstractTask.java:53) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) Caused by: org.h2.jdbc.JdbcSQLException: Concurrent update in table "BOOK": another transaction has updated or deleted the same row [90131-178] at org.h2.message.DbException.getJdbcSQLException(DbException.java:344) at org.h2.message.DbException.get(DbException.java:178) at org.h2.message.DbException.get(DbException.java:154) at org.h2.mvstore.db.MVPrimaryIndex.remove(MVPrimaryIndex.java:170) at org.h2.mvstore.db.MVTable.removeRow(MVTable.java:584) at org.h2.table.Table.updateRows(Table.java:456) at org.h2.command.dml.Update.update(Update.java:146) at org.h2.command.CommandContainer.update(CommandContainer.java:79) at org.h2.command.Command.executeUpdate(Command.java:254) at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:158) at org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:144) at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175) at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3198) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3077) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3457) at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:145) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:589) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:463) at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337) at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1437) at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:493) at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3207) at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2413) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:467) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:156) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231) at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68) at org.hibernate.search.test.performance.task.AbstractTask.run(AbstractTask.java:53) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748)

Source: http://ci.hibernate.org/job/hibernate-search-master/org.hibernate$hibernate-search-performance-orm/1115/testReport/junit/org.hibernate.search.test.performance/TestRunnerStandalone/runPerformanceTest/

The exact cause is the update tasks in that test, such as UpdateBookRatingTask or UpdateBookTotalSoldTask. Those tasks execute concurrently, and they pick an entity ID randomly to perform the update on. In smoke tests, there are very few entities (10, I think) and thus a conflict is very likely.

Environment

None

Status

Assignee

Yoann Rodière

Reporter

Yoann Rodière

Components

Priority

Major