Hibernate PessimisticLockingFailureException Occurring at a particular time everyday

Question

I have a Spring Boot application and hibernate exception comes every day at a particular time at night. The exception is :

could not execute statement; SQL [n/a]; nested exception is org.hibernate.PessimisticLockException: could not execute statement

The following is the stack trace :

Caused by: org.hibernate.PessimisticLockException: could not execute statement
    at org.hibernate.dialect.MySQLDialect$3.convert(MySQLDialect.java:537)
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:200)
    at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3421)
    at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3283)
    at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3695)
    at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:149)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
    at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
    at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
    at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:348)
    at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
    at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:108)
    at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1344)
    at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:435)
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3221)
    at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2389)
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281)
    at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:534)
    ... 117 common frames omitted
Caused by: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:123)
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
    at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:953)
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1092)
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1040)
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeLargeUpdate(ClientPreparedStatement.java:1347)
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdate(ClientPreparedStatement.java:1025)
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:410)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:197)
    ... 138 common frames omitted

I have checked logs and unable to find any major problems which might be triggering this problem. Can anyone guide on how to debug this particular problem or what approach to take to analyze this exception?

Answer 1

It seems that MySQLTransactionRollbackException indicates the transaction is waiting for the lock from another transaction to be released. The fact that you have mentioned it occurs at a particular time of the day indicates some scheduled backup job or some other job that is running on that particular table.

In MySQL, for example, this information is stored in the INFORMATION_SCHEMA.EVENTS table, so you can run SELECT * FROM INFORMATION_SCHEMA.EVENTS to see the list of scheduled jobs and information about them.