SQL: delete from jhi_persistent_audit_event where event_id=? , Batch update returned unexpected row count from update [0];

user_2087270 0
Viewed 681

I have a Jhipster Spring boot in production and after a while it gives this error: 

SQL: delete from jhi_persistent_audit_event where event_id=?

.

 HHH000315: Exception executing batch [org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1], SQL: delete from jhi_persistent_audit_event where event_id=?
    2020-03-01 12:00:00.132 ERROR 14354 --- [ms-scheduling-1] o.h.i.ExceptionMapperStandardImpl        : HHH000346: Error during managed flush [Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1]
    2020-03-01 12:00:00.137 ERROR 14354 --- [ms-scheduling-1] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task.

 Unexpected error occurred in scheduled task.

org.springframework.orm.ObjectOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:339)
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:254)
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:537)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:534)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:305)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at com.gotop.nms.service.AuditEventService$$EnhancerBySpringCGLIB$$3c01613a.removeOldAuditEvents(<generated>)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84)
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
    at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:93)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
    at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67)
    at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54)
    at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.checkRowCounts(BatchingBatch.java:149)
    at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:124)
    at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.addToBatch(BatchingBatch.java:89)
    at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3498)
    at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3755)
    at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:99)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478)
    at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356)
    at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
    at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1483)
    at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:512)
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3321)
    at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2517)
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:178)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:39)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:271)
    at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:104)
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:533)
    ... 22 common frames omitted

The database is Mysql

This exception maybe can happen while deleting a record by Id that does not exists at all. So how do I fix this is JHipster.

Where do you think this SQL is called ?

jhipster spring-boot
1 Answers

This occurs in removeOldAuditEvents method of AuditEventService which is annotated with @Transactionnal at class level.

This method is @Scheduled annotated and you have multiple instances of your app running. So, each day at same hour all your instances compete to purge events older than 30 days.

This is a classical case of batch jobs in multiple instances apps.

So, you have several alternatives:

  • select an instance responsible for purging events maybe with a spring profile
  • externalize the scheduling by exposing your purge method as an API endpoint (see AuditResource) correctly secured that you will call from a cron or any external scheduler and using an API gateway to route to only one instance
  • catch ObjectOptimisticLockingFailureException and ignore it in this method; in general it's not recommended but in this case I guess it is acceptable because one instance will succeed and this is what you want. Maybe configuring pessimistic locking would make sense.
  • implement a distributed lock either in database or in Hazelcast that you might already use for distributed caching
user_939600
Related