Deadlock / Concurrency Exception when creating multiple job threads

[mchenryed]

I have been struggling with spring batch for a few days. We have a process that monitors a directory and when a new file appears in the directory, we kick off a spring batch asynchronous process that will process the incoming file. It works great if we copy a single file in the directory, but we have deadlock issues when we copy several files into the directory. The deadlock appears when it is creating itself into the H2 database.

I have seen this problem in other posts (ConcurrencyExceptions / DeadlockExceptions) and I have tried the suggested solutions and they have not worked. We are using 2.1.7.RELEASE of spring batch.

Here is a snapshot of the exception:

08:35:47,322 ERROR AbstractJob:306 - Encountered fatal error executing job
org.springframework.batch.core.JobExecutionException: Flow execution ended unexpectedly
	at org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:141)
	at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:281)
	at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:120)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
Caused by: org.springframework.batch.core.job.flow.FlowExecutionException: Ended flow=ZipFileJob at state=ZipFileJob.Teachers with exception
	at org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:152)
	at org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:124)
	at org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:135)
	... 5 more
Caused by: org.springframework.dao.ConcurrencyFailureException: PreparedStatementCallback; SQL [INSERT INTO BATCH_STEP_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, STEP_EXECUTION_ID) VALUES(?, ?, ?)]; Deadlock detected. The current transaction was rolled back. Details: "
Session #2 (user: SA) is waiting to lock PUBLIC.BATCH_STEP_EXECUTION while locking PUBLIC.BATCH_STEP_EXECUTION_CONTEXT (exclusive).
Session #6 (user: SA) is waiting to lock PUBLIC.BATCH_STEP_EXECUTION_CONTEXT while locking PUBLIC.BATCH_STEP_EXECUTION (exclusive)."; SQL statement:
INSERT INTO BATCH_STEP_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, STEP_EXECUTION_ID) VALUES(?, ?, ?) [40001-162]; nested exception is org.h2.jdbc.JdbcSQLException: Deadlock detected. The current transaction was rolled back. Details: "
Session #2 (user: SA) is waiting to lock PUBLIC.BATCH_STEP_EXECUTION while locking PUBLIC.BATCH_STEP_EXECUTION_CONTEXT (exclusive).
Session #6 (user: SA) is waiting to lock PUBLIC.BATCH_STEP_EXECUTION_CONTEXT while locking PUBLIC.BATCH_STEP_EXECUTION (exclusive)."; SQL statement:
INSERT INTO BATCH_STEP_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, STEP_EXECUTION_ID) VALUES(?, ?, ?) [40001-162]
	at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:110)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80)
	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:603)
	at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:812)
	at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:868)
	at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.persistSerializedContext(JdbcExecutionContextDao.java:193)
	at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.saveExecutionContext(JdbcExecutionContextDao.java:159)
	at org.springframework.batch.core.repository.support.SimpleJobRepository.add(SimpleJobRepository.java:163)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at $Proxy11.add(Unknown Source)
	at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:131)

Here is a snippet from the spring configuration file:

    <bean id="transactionManager" class="org.springframework.jdbc.datasource.DataSourceTransactionManager">
        <property name="dataSource" ref="dataSource"/>
    </bean>

    <bean id="jobExecutor" class="org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor">
   	     <property name="corePoolSize" value="5" />
   	     <property name="maxPoolSize" value="10" />
   	     <property name="queueCapacity" value="25" />
   	</bean>

    <bean id="jobLauncher" class="org.springframework.batch.core.launch.support.SimpleJobLauncher">
        <property name="jobRepository" ref="jobRepository" />
        <property name="taskExecutor" ref="jobExecutor" />
    </bean>
    
    <bean id="jobRepository" class="org.springframework.batch.core.repository.support.JobRepositoryFactoryBean" >
   		<property name="databaseType" value="h2" />
   		<property name="dataSource" ref="dataSource" />
   		<property name="transactionManager" ref="transactionManager" />
   		<property name="isolationLevelForCreate" value="ISOLATION_READ_UNCOMMITTED"/>
   	</bean>

I have tried just about every combination of isolationLevelForCreate value possible with no success (most posts indicate that is the problem).

Finally, here is the code on where we create a job:

    @Autowired
    JobLauncher jobLauncher;

    @Autowired
   	private Job job;

    private void fileProcessor(String fileToManage) {
        logger.debug("Processing file: " + fileToManage);
        JobParameters params = new JobParametersBuilder()
               .addString(JobConstants.ZIP_FILE_NAME, fileToManage)
               .addDate("date", new Date())
               .toJobParameters();
        try {
            jobLauncher.run(job, params);
            logger.debug("Submitted file: " + fileToManage);
        } catch (Exception e) {
           logger.error("Error submitting job for filename: " + fileToManage, e);
        }
   }

Any suggestions would be appreciated.

[mminella]

While it does not look like it from the code you've posted, is that fileProcessor method call wrapped in any type of transaction?

[mchenryed]

No. I am not starting any transactions on my own.

Interestingly, I am copying about 7 files into the directory at once. It will process about 5 of them, while 2 or 3 will bomb out with the deadlock exception.

I have been looking at putting in retry logic but the code examples I've found aren't very helpful.

It seems like this has been an ongoing problem with Spring Batch, as I see people with similar stack dumps going back 2 - 3 years. I did try 2.1.9 and that didn't help and I tried the nightly build version and at first I had 100% success but I tried it again (by copying more files into the directory) and I got the same stack dump.

I really think that since several threads running, Spring Batch is trying to update / query its own tables and they are deadlocking with each other.

[mminella]

Can we see the configuration of the job itself (a test case that recreates the error would be very helpful if you have one)? Without knowing too much about how that fileProcessor method is called, I see that it is not synchronized by itself so one of the scenarios that pop to mind would be two jobs trying to process the same file (aka starting the same job twice) but it's hard to tell with the information above...