1

I have multiple threads that start jobs using a synchronous job launcher. I get the following exception when job instances are created concurrently:

Exception in thread "pool-1-thread-1" org.springframework.dao.DataAccessResourceFailureException: Could not obtain last_insert_id(); nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at org.springframework.jdbc.support.incrementer.MySQLMaxValueIncrementer.getNextKey(MySQLMaxValueIncrementer.java:118)
    at org.springframework.jdbc.support.incrementer.AbstractDataFieldMaxValueIncrementer.nextLongValue(AbstractDataFieldMaxValueIncrementer.java:128)
    at org.springframework.batch.core.repository.dao.JdbcJobInstanceDao.createJobInstance(JdbcJobInstanceDao.java:109)
    at org.springframework.batch.core.repository.support.SimpleJobRepository.createJobExecution(SimpleJobRepository.java:135)
    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:497)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.batch.core.repository.support.AbstractJobRepositoryFactoryBean$1.invoke(AbstractJobRepositoryFactoryBean.java:172)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy36.createJobExecution(Unknown Source)
    at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:125)
    at com.example.JobTask.run(JobTask.java:122)
    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:745)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:389)
    at com.mysql.jdbc.Util.getInstance(Util.java:372)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3835)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3771)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2531)
    at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1618)
    at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1549)
    at com.mchange.v2.c3p0.impl.NewProxyStatement.executeUpdate(NewProxyStatement.java:436)
    at org.springframework.jdbc.support.incrementer.MySQLMaxValueIncrementer.getNextKey(MySQLMaxValueIncrementer.java:102)
    ... 23 more


Exception in thread "pool-2-thread-1" org.springframework.dao.DataAccessResourceFailureException: Could not obtain last_insert_id(); nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at org.springframework.jdbc.support.incrementer.MySQLMaxValueIncrementer.getNextKey(MySQLMaxValueIncrementer.java:118)
    at org.springframework.jdbc.support.incrementer.AbstractDataFieldMaxValueIncrementer.nextLongValue(AbstractDataFieldMaxValueIncrementer.java:128)
    at org.springframework.batch.core.repository.dao.JdbcJobInstanceDao.createJobInstance(JdbcJobInstanceDao.java:109)
    at org.springframework.batch.core.repository.support.SimpleJobRepository.createJobExecution(SimpleJobRepository.java:135)
    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:497)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.batch.core.repository.support.AbstractJobRepositoryFactoryBean$1.invoke(AbstractJobRepositoryFactoryBean.java:172)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy36.createJobExecution(Unknown Source)
    at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:125)
    at com.example.JobTask.run(JobTask.java:122)
    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:745)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:389)
    at com.mysql.jdbc.Util.getInstance(Util.java:372)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3835)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3771)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2531)
    at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1618)
    at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1549)
    at com.mchange.v2.c3p0.impl.NewProxyStatement.executeUpdate(NewProxyStatement.java:436)
    at org.springframework.jdbc.support.incrementer.MySQLMaxValueIncrementer.getNextKey(MySQLMaxValueIncrementer.java:102)
    ... 23 more

If that helps, here is the output of the SHOW ENGINE INNODB STATUS command:

=====================================
2015-11-10 13:28:12 7fcb28845700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 54 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 635 srv_active, 0 srv_shutdown, 52429 srv_idle
srv_master_thread log flush and writes: 53064
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 308
OS WAIT ARRAY INFO: signal count 299
Mutex spin waits 286, rounds 1715, OS waits 43
RW-shared spins 264, rounds 7805, OS waits 258
RW-excl spins 23, rounds 456, OS waits 5
Spin rounds per wait: 6.00 mutex, 29.56 RW-shared, 19.83 RW-excl
------------------------
LATEST DETECTED DEADLOCK
------------------------
2015-11-10 10:53:26 7fcb28539700
*** (1) TRANSACTION:
TRANSACTION 713122, ACTIVE 1 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 6 lock struct(s), heap size 1184, 4 row lock(s), undo log entries 2
MySQL thread id 59, OS thread handle 0x7fcb2867e700, query id 35893 92.240.15.2 root update
INSERT into BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION) values (1, 'CSV', 'd52c9dc2e62cf24ec305728b7a2c5c0a', 0)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 135 page no 4 n bits 72 index `JOB_INST_UN` of table `spring_batch`.`BATCH_JOB_INSTANCE` trx id 713122 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) TRANSACTION:
TRANSACTION 713124, ACTIVE 0 sec starting index read, thread declared inside InnoDB 5000
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1184, 2 row lock(s)
MySQL thread id 68, OS thread handle 0x7fcb28539700, query id 35895 92.240.15.2 root updating
update BATCH_JOB_SEQ set ID = last_insert_id(ID + 1)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 135 page no 4 n bits 72 index `JOB_INST_UN` of table `spring_batch`.`BATCH_JOB_INSTANCE` trx id 713124 lock mode S
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 143 page no 3 n bits 72 index `UNIQUE_KEY_UN` of table `spring_batch`.`BATCH_JOB_SEQ` trx id 713124 lock_mode X waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 1; hex 30; asc 0;;
 1: len 6; hex 0000000ae1a2; asc       ;;
 2: len 7; hex 3e0000019b2308; asc >    # ;;
 3: len 8; hex 8000000000000001; asc         ;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 713138
Purge done for trx's n:o < 713137 undo n:o < 0 state: running but idle
History list length 1305
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 71, OS thread handle 0x7fcb28845700, query id 35985 92.240.15.2 root init
SHOW ENGINE INNODB STATUS
---TRANSACTION 713137, not started
MySQL thread id 70, OS thread handle 0x7fcb28782700, query id 35982 92.240.15.2 root cleaning up
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
466 OS file reads, 8503 OS file writes, 5353 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 276671, node heap has 1 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 514559278
Log flushed up to   514559278
Pages flushed up to 514559278
Last checkpoint at  514559278
0 pending log writes, 0 pending chkp writes
4480 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 137363456; in additional pool allocated 0
Dictionary memory allocated 102572
Buffer pool size   8191
Free buffers       7401
Database pages     789
Old database pages 271
Modified db pages  0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 441, created 348, written 3623
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 789, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread process no. 2535, id 140510486161152, state: sleeping
Number of rows inserted 574, updated 5893, deleted 0, read 12358
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

Any idea why it happens?

I use MySQL v5.6.26.

Thanks, Mickael


EDIT:

Here is my job configuration:

addStep(new StepBuilder(partitioningStepName)
    .tasklet(partitionerTasklet)
    .repository(jobRepository)
    .transactionManager(txManager)
    .build());

addStep(new StepBuilder(processingStepName)
    .partitioner("partition", partitioner)
    .taskExecutor(new SimpleAsyncTaskExecutor())
    .step(new StepBuilder(processingStepName)
                .<ItemWrapper<Request>, ItemWrapper<Request>>chunk(1000)
                .reader(commonReader)
                .writer(writer)
                .repository(jobRepository)
                .transactionManager(txManager)
                .listener(failureListener)
                .build())
    .repository(jobRepository)
    .transactionManager(txManager)
    .build());

addStep(new StepBuilder(mergingStepName)
    .tasklet(mergerTasklet)
    .repository(jobRepository)
    .transactionManager(txManager)
    .build());

I tried to put a breakpoint at the line that launches the job:

jobExecution = jobLauncher.run(job, jobParameters);

I can see that my threads all stop at this line. Then, I let them run one after the other waiting for awhile between launches and no deadlock occurs as expected. According to the MySQL log, it looks like the first transaction already obtains the next ID and is inserting a job instance. However, the second transaction is stuck while getting the next ID. According to the javadoc of the MySQLMaxValueIncrementer class, the MyISAM engine should be used for the sequence tables (see the issue I created). Therefore, I tried to use MyISAM instead of InnoDB and now I still get deadlock but only on the INSERT part. Therefore the exceptions look like this:

Exception in thread "pool-1-thread-1"
org.springframework.dao.DeadlockLoserDataAccessException: PreparedStatementCallback; SQL [INSERT into BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION) values (?, ?, ?, ?)]; Deadlock found when trying to get lock; try restarting transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:263)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:660)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:909)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:970)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:975)
    at org.springframework.batch.core.repository.dao.JdbcJobInstanceDao.createJobInstance(JdbcJobInstanceDao.java:116)
    at org.springframework.batch.core.repository.support.SimpleJobRepository.createJobExecution(SimpleJobRepository.java:135)
    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:497)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.batch.core.repository.support.AbstractJobRepositoryFactoryBean$1.invoke(AbstractJobRepositoryFactoryBean.java:172)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy36.createJobExecution(Unknown Source)
    at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:125)
    at com.example.JobTask.run(JobTask.java:122)
    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:745)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:389)
    at com.mysql.jdbc.Util.getInstance(Util.java:372)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3835)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3771)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2535)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1911)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2145)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2081)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2066)
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:1449)
    at org.springframework.jdbc.core.JdbcTemplate$2.doInPreparedStatement(JdbcTemplate.java:916)
    at org.springframework.jdbc.core.JdbcTemplate$2.doInPreparedStatement(JdbcTemplate.java:909)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:644)
    ... 25 more
Exception in thread "pool-2-thread-1" org.springframework.dao.DeadlockLoserDataAccessException: PreparedStatementCallback; SQL [INSERT into BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION) values (?, ?, ?, ?)]; Deadlock found when trying to get lock; try restarting transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:263)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:660)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:909)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:970)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:975)
    at org.springframework.batch.core.repository.dao.JdbcJobInstanceDao.createJobInstance(JdbcJobInstanceDao.java:116)
    at org.springframework.batch.core.repository.support.SimpleJobRepository.createJobExecution(SimpleJobRepository.java:135)
    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:497)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.batch.core.repository.support.AbstractJobRepositoryFactoryBean$1.invoke(AbstractJobRepositoryFactoryBean.java:172)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy36.createJobExecution(Unknown Source)
    at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:125)
    at com.example.JobTask.run(JobTask.java:122)
    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:745)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:389)
    at com.mysql.jdbc.Util.getInstance(Util.java:372)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3835)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3771)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2535)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1911)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2145)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2081)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2066)
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:1449)
    at org.springframework.jdbc.core.JdbcTemplate$2.doInPreparedStatement(JdbcTemplate.java:916)
    at org.springframework.jdbc.core.JdbcTemplate$2.doInPreparedStatement(JdbcTemplate.java:909)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:644)
    ... 25 more

And now, looking at the MySQL log, all the involved locks are on the same table. I don't understand why concurrent INSERT on the same table (and involving only one table) may cause a deadlock.

More information, the deadlock is related to the presence of the unique constraint on the JOB_INSTANCE table. Before INSERT, MySQL locks records in the index and the deadlock occurs between the concurrent transactions.

manash
  • 6,985
  • 12
  • 65
  • 125
  • Deadlock involves two threads and having two locks A and B entered by both, and then doing B (resp. A), blocking. Here the rollback seems involved (and then doing a restart?). Maybe an exclusive lock is needed. – Joop Eggen Nov 10 '15 at 12:48
  • Take a look in this thread: http://stackoverflow.com/questions/17747906/getting-deadlock-found-when-trying-to-get-lock-try-restarting-transaction – Will Glück Nov 10 '15 at 12:49
  • @JoopEggen is there a way to avoid such deadlocks? – manash Nov 10 '15 at 13:21
  • please share your job and database/transactionmanager setup – Michael Pralow Nov 10 '15 at 13:57
  • @MichaelPralow Regarding database and tx manager, I use the default. I simply use the EnableBatchProcessing annotation on my configuration class. I guess that default beans are created in such case. Regarding job config, please see my edit. – manash Nov 10 '15 at 14:03
  • You might only proceed differently. Lock explicitly, avoid long transactions. That there _is_ a deadlock is the sad thing because it involves two lock points. A pragmatic solution would be to do a batch insert at midnight and lock the rest, maybe even on app level: site in maintenance. – Joop Eggen Nov 10 '15 at 14:06
  • @JoopEggen The deadlock seems to occur between multiple concurrent batch jobs and I can't avoid concurrency, that would be simply wrong. I strongly doubt Spring Batch doesn't work well when multiple jobs execute concurrently. – manash Nov 10 '15 at 15:40
  • please share more config details for the "txManager" (obviously not the one used by Spring for jobRepo) and how you run the job(s) – Michael Pralow Nov 10 '15 at 22:34
  • @MichaelPralow I don't define any transaction manager myself. My jobs don't need transactions (they work with a MongoDB database). I use MySQL only for storing Spring Batch metadata. Therefore, I rely on the tx manager created implicitly by Spring. If you look at the DefaultBatchConfigurer class, you can see that the tx manager is a Spring DataSourceTransactionManager created using my DataSource. – manash Nov 11 '15 at 08:59
  • @MichaelPralow If you are interested by specific properties of the tx manager, I can put a breakpoint and find the information. – manash Nov 11 '15 at 09:07
  • for stepBuilder convenience - see http://docs.spring.io/spring-batch/reference/html/configureJob.html, what is still missing is the part - how do you run the job? JUnit? deployed somewhere? executable jar? – Michael Pralow Nov 11 '15 at 09:43
  • @MichaelPralow The jobs are launched using a job launcher shared by multiple threads that I create myself. So it's simply a matter of calling jobLauncher.run(job, jobParameters); on every thread. – manash Nov 11 '15 at 09:47
  • @MichaelPralow I edited my question to add more information. – manash Nov 11 '15 at 09:52
  • Hi @MickaelMarrache, were you able to find a solution for your problem? Because I read and tried all things in this thread, but not worked. – Serkan Yıldırım Nov 10 '20 at 11:57

2 Answers2

4

The problem comes from shared lock. By default, createJobExecution method executes within the transaction with serializable isolation level. When this isolation level is used, InnoDB implicitly converts all plain SELECT statements to SELECT ... LOCK IN SHARE MODE. Hence, JOB_INST_UN is locked shared because of query against instance table. And then, when insert job instance, an exclusive lock on JOB_INST_UN is required. Deadlock appeared, if this unique index was locked shared by another transaction.

  • Following this bit of advice and explanation, I was able to adjust table isolation on my jobRepository bean specification : `factory.setIsolationLevelForCreate("ISOLATION_REPEATABLE_READ");` Previously it was set to: `ISOLATION_SERIALIZABLE`. This can result in some jobs being run concurrently, as outlined [here](https://docs.spring.io/spring-batch/trunk/apidocs/org/springframework/batch/core/repository/support/AbstractJobRepositoryFactoryBean.html#setIsolationLevelForCreate-java.lang.String-). – Andrew Cotton Feb 20 '19 at 23:33
0

Possible condition:

1 thread is accessing record(s) in a table that cause table lock, then another 1 is accessing that table while the lock is not lifted yet

  • If that is the case, why is it a deadlock? The thread should wait for the lock and that's all. – manash Nov 10 '15 at 12:49