Тупик Innodb, не упомянутый в ENGINE INNODB STATUS

Я получаю исключение взаимоблокировки, но когда я хочу увидеть некоторую информацию об этом из «SHOW ENGINE INNODB STATUS», она содержит информацию о взаимоблокировке более давнего времени (задолго до исключения), поэтому похоже, что она просто «не поймана» той командой.

Из трассировки стека я вижу, что последним выполненным кодом моего приложения был $Proxy174.attemptToAcquireJobExecution , который является реализацией интерфейса данных Spring:

@Transactional(TxType.REQUIRES_NEW)
@Modifying
@Query("UPDATE Job SET last_run = NOW(),
                       last_run_by=:runner
         WHERE name = :name
           AND (last_run + :interval ) < NOW()")
int attemptToAcquireJobExecution(
           @Param("name") String var1,
           @Param("interval") int var2,
           @Param("runner") String var3);

Он работает с такой простой таблицей:

CREATE TABLE `jobs` (
  `name` varchar(50) COLLATE utf8mb4_unicode_ci NOT NULL,
  `last_run_by` varchar(100) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
  `last_run` datetime(3) DEFAULT NULL,
  `context_data` varchar(100) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
  PRIMARY KEY (`name`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci;

Запланированные задачи, которые выполняют эту команду, запускаются каждые несколько минут (в 3 экземплярах приложения), поэтому риск коллизий действительно минимален, но взаимоблокировка происходит очень часто... Перед этой операцией нигде нет @Transactional, поэтому должно быть нет зависшей транзакции на самом деле. В любом случае, пинг этих команд дает пустые результаты:

SELECT * FROM INFORMATION_SCHEMA.INNODB_LOCKS ;
SELECT * FROM INFORMATION_SCHEMA.INNODB_LOCK_WAITS;

Исходная трассировка стека, мои классы отмечены как «xxx» внизу:

com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(NativeConstructorAccessorImpl.java)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
    at com.mysql.jdbc.Util.getInstance(Util.java:408)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:951)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3973)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3909)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2527)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2680)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2497)
    at com.mysql.jdbc.ConnectionImpl.commit(ConnectionImpl.java:1566)
    ... 2 frames excluded
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(ProxyConnection.java:126)
    at org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)
    at org.apache.tomcat.jdbc.pool.DisposableConnectionFacade.invoke(DisposableConnectionFacade.java:81)
    at com.sun.proxy.$Proxy121.commit(Unknown Source)
    at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.commit(AbstractLogicalConnectionImplementor.java:80)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:232)
    at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:65)
    at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:61)
    ... 49 common frames omitted
Wrapped by: javax.persistence.PersistenceException: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1692)
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602)
    at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:75)
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:517)
    ... 48 common frames omitted
Wrapped by: org.springframework.orm.jpa.JpaSystemException: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction; nested exception is javax.persistence.PersistenceException: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at org.springframework.orm.jpa.EntityManagerFactoryUtils.convertJpaAccessExceptionIfPossible(EntityManagerFactoryUtils.java:418)
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:246)
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:521)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:504)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:292)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:133)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:57)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
    at com.sun.proxy.$Proxy174.attemptToAcquireJobExecution(Unknown Source)
    at xxx.lib.scheduler.JobsService.checkIfJobShouldBeExecuted(JobsService.java:32)
    at xxx.lib.scheduler.StandardBatchStarter.startScheduled(StandardBatchStarter.java:38)
    at xxx.scheduled.ImportProductDescriptionJob.startScheduled(ImportProductDescriptionJob.java:46)
    at xxx.scheduled.ImportProductDescriptionJob$$FastClassBySpringCGLIB$$494978af.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:721)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
    at org.springframework.cloud.sleuth.instrument.scheduling.TraceSchedulingAspect.traceBackgroundThread(TraceSchedulingAspect.java:72)
    ... 2 frames excluded
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:629)
    ... 21 frames truncated

person Tomasz    schedule 19.04.2017    source источник
comment
Вы не используете блокировку строк? Проверьте, есть ли общие/эксклюзивные блокировки.   -  person Devart    schedule 19.04.2017
comment
Три экземпляра начинаются «точно» в одно и то же время?   -  person Rick James    schedule 24.04.2017
comment
Нет, не в одно и то же время. Я как бы сдался и переделал все это, чтобы основываться на оптимистичной блокировке. Похоже, тупиков больше нет. Спасибо за поддержку @RickJames   -  person Tomasz    schedule 26.04.2017


Ответы (1)


AND (last_run + :interval ) < NOW()

Вероятно, приводит к синтаксической ошибке или ошибке данных.

Предоставьте сгенерированный SQL. Я подозреваю, что он генерирует

AND (last_run + 2) < NOW()

Но это должно быть что-то вроде

AND (last_run + INTERVAL 2 DAY) < NOW()

Также укажите SHOW CREATE Job.

person Rick James    schedule 21.04.2017
comment
Привет, Рик, как уже упоминалось, это запрос JPA, он не терпит неудачу. Он генерирует такой запрос: Hibernate: набор заданий обновления last_run=now(), last_run_by=? где имя=? и last_run+?‹now() Интервал в секундах, я думаю, что это значение по умолчанию. Код таблицы CREATE также находится в вопросе. - person Tomasz; 24.04.2017
comment
(last_run + 2) работает, но не корректно. Предоставьте сгенерированный SQL. - person Rick James; 24.04.2017