Startup fails with "Cannot find any job execution for job instance".

[mcpierce]

Bug description
Our project (ComiXed) uses Spring Batch for processing. We have one configured job that is run on startup if an incompletely process is found:

spring.batch.job.name=loadPageHashesJob

After rebooting our application, it will startup and complain that it can't find this process (see stacktrace below) and prevents the application from starting. The only way to recover is to either drop the batch tables or else empty them out completely.

Environment

Java 17
Spring Boot 3.4.1
PostgreSQL 15

Steps to reproduce

1. Shut down ComiXed.
2. Restart ComiXed.
3. (Frequently) The stacktrace below is produced and the server fails to start.

Expected behavior

1. The server should start and any existing instance of the job should continue.

Minimal Complete Reproducible example
Running our server app, importing some comics, then restarting the server will produce this problem about 50% of the time.

Stacktrace

java.lang.IllegalStateException: Cannot find any job execution for job instance: JobInstance: id=83, version=0, Job=[loadPageHashesJob]
        at org.springframework.batch.core.repository.support.SimpleJobRepository.createJobExecution(SimpleJobRepository.java:139) ~[spring-batch-core-5.1.1.jar!/:5.1.1]
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na]
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
        at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:351) ~[spring-aop-6.1.4.jar!/:6.1.4]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196) ~[spring-aop-6.1.4.jar!/:6.1.4]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-6.1.4.jar!/:6.1.4]
        at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-6.1.4.jar!/:6.1.4]
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:385) ~[spring-tx-6.1.4.jar!/:6.1.4]
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-6.1.4.jar!/:6.1.4]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) ~[spring-aop-6.1.4.jar!/:6.1.4]
        at org.springframework.batch.core.repository.support.AbstractJobRepositoryFactoryBean.lambda$getObject$0(AbstractJobRepositoryFactoryBean.java:204) ~[spring-batch-core-5.1.1.jar!/:5.1.1]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) ~[spring-aop-6.1.4.jar!/:6.1.4]
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:220) ~[spring-aop-6.1.4.jar!/:6.1.4]
        at jdk.proxy2/jdk.proxy2.$Proxy200.createJobExecution(Unknown Source) ~[na:na]
        at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:145) ~[spring-batch-core-5.1.1.jar!/:5.1.1]
        at org.springframework.batch.core.launch.support.TaskExecutorJobLauncher.run(TaskExecutorJobLauncher.java:59) ~[spring-batch-core-5.1.1.jar!/:5.1.1]
        at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.execute(JobLauncherApplicationRunner.java:210) ~[spring-boot-autoconfigure-3.2.3.jar!/:3.2.3]
        at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.executeLocalJobs(JobLauncherApplicationRunner.java:194) ~[spring-boot-autoconfigure-3.2.3.jar!/:3.2.3]
        at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.launchJobFromProperties(JobLauncherApplicationRunner.java:174) ~[spring-boot-autoconfigure-3.2.3.jar!/:3.2.3]
        at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.run(JobLauncherApplicationRunner.java:169) ~[spring-boot-autoconfigure-3.2.3.jar!/:3.2.3]
        at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.run(JobLauncherApplicationRunner.java:164) ~[spring-boot-autoconfigure-3.2.3.jar!/:3.2.3]
        at org.springframework.boot.SpringApplication.lambda$callRunner$4(SpringApplication.java:786) ~[spring-boot-3.2.3.jar!/:3.2.3]
        at org.springframework.util.function.ThrowingConsumer$1.acceptWithException(ThrowingConsumer.java:83) ~[spring-core-6.1.4.jar!/:6.1.4]
        at org.springframework.util.function.ThrowingConsumer.accept(ThrowingConsumer.java:60) ~[spring-core-6.1.4.jar!/:6.1.4]
        at org.springframework.util.function.ThrowingConsumer$1.accept(ThrowingConsumer.java:88) ~[spring-core-6.1.4.jar!/:6.1.4]
        at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:798) ~[spring-boot-3.2.3.jar!/:3.2.3]
        at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:786) ~[spring-boot-3.2.3.jar!/:3.2.3]
        at org.springframework.boot.SpringApplication.lambda$callRunners$3(SpringApplication.java:774) ~[spring-boot-3.2.3.jar!/:3.2.3]
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[na:na]
        at java.base/java.util.stream.SortedOps$SizedRefSortingSink.end(SortedOps.java:357) ~[na:na]
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:510) ~[na:na]
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[na:na]
        at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[na:na]
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[na:na]
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[na:na]
        at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[na:na]
        at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:774) ~[spring-boot-3.2.3.jar!/:3.2.3]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:341) ~[spring-boot-3.2.3.jar!/:3.2.3]
        at org.comixedproject.ComiXedApp.main(ComiXedApp.java:42) ~[!/:2.3.6]
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na]
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
        at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
        at org.springframework.boot.loader.launch.Launcher.launch(Launcher.java:91) ~[comixed-app-2.3.6.jar:2.3.6]
        at org.springframework.boot.loader.launch.Launcher.launch(Launcher.java:53) ~[comixed-app-2.3.6.jar:2.3.6]
        at org.springframework.boot.loader.launch.PropertiesLauncher.main(PropertiesLauncher.java:574) ~[comixed-app-2.3.6.jar:2.3.6]

[fmbenhassine]

This is a very unlikely situation where a job instance is created and no job executions are actually run. The issue could be related to the transaction isolation level of the job repository, but I need to be able to reproduce the case to confirm that.

What is the transaction isolation level of the job repository? Are you re-running the same job instance on restart (ie using the same job parameters as the previous run)?

If you can isolate the issue in a docker based test or in a minimal example, I would be happy to help and dig deeper. There is a project template that you can start with here.

[mcpierce]

@fmbenhassine Thanks for responding!

In our project we're not touching anything inside of the batch framework: the only interaction is through creating the job, assigning parameters, and firing it off. On restart we're not relaunching any existing job ourselves, but instead have the property mentioned in the ticket to tell Spring Batch what existing job should be restarted if present.

This particular job, when it's launched by our app, has a job property ("job.load-page-hashes.started") that is set using the value from System.currentTimeMillis() when it's initially launched. And we have code in place to look for an existing running instance of this job before deciding to start a new process.

I'll take the same template and see about putting together a small reproducer this weekend.