Innodb блокиране, не е споменато в ENGINE INNODB STATUS

Получавам изключение за блокиране, но когато искам да видя малко информация за това от „ПОКАЖЕТЕ СЪСТОЯНИЕТО НА INNODB НА ДВИГАТЕЛЯ“, то съдържа информация за блокиране от по-отдавна (много преди изключението), така че изглежда, че просто „не е уловено“ по тази команда.

От stacktrace мога да видя, че последният изпълнен код на моето приложение беше $Proxy174.attemptToAcquireJobExecution, което е реализация на пролетния интерфейс за данни:

@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 никъде преди тази операция, така че трябва да има наистина няма висяща транзакция. Както и да е, ping на тези команди дава празни резултати:

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

Оригинален stacktrace, моите класове са маркирани като "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
3-те инстанции започват ли „точно“ по едно и също време?   -  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