Skip to content

MongoStepExecutionDao returns an different stepExecution if a job has multiple steps #3

Closed
@aso-so

Description

@aso-so

Hello Team,

I found this project when I wanted to try using Spring Batch with MongoDB.
Thank you for your wonderful experiment.

I noticed a behavior like a bug, so I'm reporting it.

Version
spring-batch-experimental:0.3.0

description
MongoStepExecutionDao
getLastStepExecution(JobInstance jobInstance, String stepName) method returns a different stepExecution if a job has multiple steps. It requires a stepName argument but is not used. To get the correct step, stepName must be used.

I actually tried running the below job.

  • Step1: Always Success
  • Step2: Always Failure

If the job retry (with the same jobParameters), typically only the 'failed Step2' will be re-executed.
However, when I actually did this, the job succeeded without any steps.
The cause was that when calling the above method with the name of Step2 as an argument, it was supposed to return Step2, but instead it returned Step1 as the lastStepExecution.

Below is MongoDB's documents of the BATCH_JOB_EXECUTION after execution.

1st execution
{
  "_id": {
    "$oid": "665eda65fc3d1f6efa303756"
  },
  "jobExecutionId": {
    "$numberLong": "1"
  },
  "jobInstanceId": {
    "$numberLong": "1"
  },
  "jobParameters": {
    "runtime": {
      "value": "20240604181205",
      "type": "java.lang.String",
      "identifying": true
    }
  },
  "stepExecutions": [
    {
      "stepExecutionId": {
        "$numberLong": "1"
      },
      "jobExecutionId": {
        "$numberLong": "1"
      },
      "name": "step1",
      "status": "COMPLETED",
      "readCount": {
        "$numberLong": "0"
      },
      "writeCount": {
        "$numberLong": "0"
      },
      "commitCount": {
        "$numberLong": "1"
      },
      "rollbackCount": {
        "$numberLong": "0"
      },
      "readSkipCount": {
        "$numberLong": "0"
      },
      "processSkipCount": {
        "$numberLong": "0"
      },
      "writeSkipCount": {
        "$numberLong": "0"
      },
      "filterCount": {
        "$numberLong": "0"
      },
      "startTime": {
        "$date": "2024-06-04T09:12:06.196Z"
      },
      "createTime": {
        "$date": "2024-06-04T09:12:06.083Z"
      },
      "endTime": {
        "$date": "2024-06-04T09:12:06.340Z"
      },
      "lastUpdated": {
        "$date": "2024-06-04T09:12:06.341Z"
      },
      "executionContext": {
        "map": {
          "batch.version": "5.1.2",
          "batch.taskletType": "com.example.batchretry.BatchTasklet1",
          "batch.stepType": "org.springframework.batch.core.step.tasklet.TaskletStep",
          "batch.executed": true
        },
        "dirty": true
      },
      "exitStatus": {
        "exitCode": "COMPLETED",
        "exitDescription": ""
      },
      "terminateOnly": false
    },
    {
      "stepExecutionId": {
        "$numberLong": "2"
      },
      "jobExecutionId": {
        "$numberLong": "1"
      },
      "name": "step2",
      "status": "FAILED",
      "readCount": {
        "$numberLong": "0"
      },
      "writeCount": {
        "$numberLong": "0"
      },
      "commitCount": {
        "$numberLong": "0"
      },
      "rollbackCount": {
        "$numberLong": "1"
      },
      "readSkipCount": {
        "$numberLong": "0"
      },
      "processSkipCount": {
        "$numberLong": "0"
      },
      "writeSkipCount": {
        "$numberLong": "0"
      },
      "filterCount": {
        "$numberLong": "0"
      },
      "startTime": {
        "$date": "2024-06-04T09:12:06.535Z"
      },
      "createTime": {
        "$date": "2024-06-04T09:12:06.458Z"
      },
      "endTime": {
        "$date": "2024-06-04T09:12:06.638Z"
      },
      "lastUpdated": {
        "$date": "2024-06-04T09:12:06.638Z"
      },
      "executionContext": {
        "map": {
          "batch.version": "5.1.2",
          "batch.taskletType": "com.example.batchretry.BatchTasklet2",
          "batch.stepType": "org.springframework.batch.core.step.tasklet.TaskletStep",
          "batch.executed": true
        },
        "dirty": true
      },
      "exitStatus": {
        "exitCode": "FAILED",
        "exitDescription": "java.lang.UnsupportedOperationException: Unimplemented method 'execute'\n\tat com.example.batchretry.BatchTasklet2.execute(BatchTasklet2.java:13)\n\tat org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:388)\n\tat org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:312)\n\tat org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)\n\tat org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:255)\n\tat org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:82)\n\tat org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:369)\n\tat org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:206)\n\tat org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:140)\n\tat org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:240)\n\tat org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:229)\n\tat org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:153)\n\tat org.springframework.batch.core.job.AbstractJob.handleStep(AbstractJob.java:418)\n\tat org.springframework.batch.core.job.SimpleJob.doExecute(SimpleJob.java:132)\n\tat org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:317)\n\tat org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:157)\n\tat org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50)\n\tat org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:148)\n\tat org.springframework.batch.core.launch.support.TaskExecutorJobLauncher.run(TaskExecutorJobLauncher.java:59)\n\tat com.example.batchretry.BatchJobLauncher.run(BatchJobLauncher.java:33)\n\tat org.springframework.boot.SpringApplication.lambda$callRunner$5(SpringApplication.java:790)\n\tat org.springframework.util.function.ThrowingConsumer$1.acceptWithException(ThrowingConsumer.java:83)\n\tat org.springframework.util.function.ThrowingConsumer.accept(ThrowingConsumer.java:60)\n\tat org.springframework.util.function.ThrowingConsumer$1.accept(ThrowingConsumer.java:88)\n\tat org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:798)\n\tat org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:789)\n\tat org.springframework.boot.SpringApplication.lambda$callRunners$3(SpringApplication.java:774)\n\tat java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)\n\tat java.base/java.util.stream.SortedOps$SizedRefSortingSink.end(SortedOps.java:357)\n\tat java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:510)\n\tat java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)\n\tat java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)\n\tat java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)\n\tat java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)\n\tat java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)\n\tat org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:774)\n\tat org.springframework.boot.SpringApplication.run(SpringApplication.java:342)\n\tat org.springframework.boot.SpringApplication.run(SpringApplication.java:1363)\n\tat org.springframework.boot.SpringApplication.run(SpringApplication.java:1352)\n\tat com.example.batchretry.BatchApplication.main(BatchApplication.java:11)\n"
      },
      "terminateOnly": false
    }
  ],
  "status": "FAILED",
  "startTime": {
    "$date": "2024-06-04T09:12:05.979Z"
  },
  "createTime": {
    "$date": "2024-06-04T09:12:05.881Z"
  },
  "endTime": {
    "$date": "2024-06-04T09:12:06.701Z"
  },
  "lastUpdated": {
    "$date": "2024-06-04T09:12:06.701Z"
  },
  "exitStatus": {
    "exitCode": "FAILED",
    "exitDescription": "java.lang.UnsupportedOperationException: Unimplemented method 'execute'\n\tat com.example.batchretry.BatchTasklet2.execute(BatchTasklet2.java:13)\n\tat org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:388)\n\tat org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:312)\n\tat org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)\n\tat org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:255)\n\tat org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:82)\n\tat org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:369)\n\tat org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:206)\n\tat org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:140)\n\tat org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:240)\n\tat org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:229)\n\tat org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:153)\n\tat org.springframework.batch.core.job.AbstractJob.handleStep(AbstractJob.java:418)\n\tat org.springframework.batch.core.job.SimpleJob.doExecute(SimpleJob.java:132)\n\tat org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:317)\n\tat org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:157)\n\tat org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50)\n\tat org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:148)\n\tat org.springframework.batch.core.launch.support.TaskExecutorJobLauncher.run(TaskExecutorJobLauncher.java:59)\n\tat com.example.batchretry.BatchJobLauncher.run(BatchJobLauncher.java:33)\n\tat org.springframework.boot.SpringApplication.lambda$callRunner$5(SpringApplication.java:790)\n\tat org.springframework.util.function.ThrowingConsumer$1.acceptWithException(ThrowingConsumer.java:83)\n\tat org.springframework.util.function.ThrowingConsumer.accept(ThrowingConsumer.java:60)\n\tat org.springframework.util.function.ThrowingConsumer$1.accept(ThrowingConsumer.java:88)\n\tat org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:798)\n\tat org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:789)\n\tat org.springframework.boot.SpringApplication.lambda$callRunners$3(SpringApplication.java:774)\n\tat java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)\n\tat java.base/java.util.stream.SortedOps$SizedRefSortingSink.end(SortedOps.java:357)\n\tat java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:510)\n\tat java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)\n\tat java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)\n\tat java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)\n\tat java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)\n\tat java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)\n\tat org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:774)\n\tat org.springframework.boot.SpringApplication.run(SpringApplication.java:342)\n\tat org.springframework.boot.SpringApplication.run(SpringApplication.java:1363)\n\tat org.springframework.boot.SpringApplication.run(SpringApplication.java:1352)\n\tat com.example.batchretry.BatchApplication.main(BatchApplication.java:11)\n"
  },
  "executionContext": {
    "map": {
      "batch.version": "5.1.2"
    },
    "dirty": true
  },
  "_class": "org.springframework.batch.experimental.core.repository.persistence.JobExecution"
}
2nd execution
{
  "_id": {
    "$oid": "665edacf5f27d077ac004dcc"
  },
  "jobExecutionId": {
    "$numberLong": "2"
  },
  "jobInstanceId": {
    "$numberLong": "1"
  },
  "jobParameters": {
    "runtime": {
      "value": "20240604181205",
      "type": "java.lang.String",
      "identifying": true
    }
  },
  "stepExecutions": [],
  "status": "COMPLETED",
  "startTime": {
    "$date": "2024-06-04T09:13:51.647Z"
  },
  "createTime": {
    "$date": "2024-06-04T09:13:51.492Z"
  },
  "endTime": {
    "$date": "2024-06-04T09:13:51.815Z"
  },
  "lastUpdated": {
    "$date": "2024-06-04T09:13:51.815Z"
  },
  "exitStatus": {
    "exitCode": "NOOP",
    "exitDescription": "All steps already completed or no steps configured for this job."
  },
  "executionContext": {
    "map": {
      "batch.version": "5.1.2"
    },
    "dirty": true
  },
  "_class": "org.springframework.batch.experimental.core.repository.persistence.JobExecution"
}

log: Step1 is returned as 'lastStepExecution' in each step
2024-06-04T18:13:51.123+09:00  INFO 2568 --- [batchretry] [ngodb.net:27017] org.mongodb.driver.cluster               : Discovered replica set primary ac-m8tqexx-shard-00-02.ioxkzup.mongodb.net:27017 with max election id 7fffffff00000000000000b4 and max set version 7
2024-06-04T18:13:51.642+09:00  INFO 2568 --- [batchretry] [           main] o.s.b.c.l.support.SimpleJobLauncher      : Job: [SimpleJob: [name=testJob]] launched with the following parameters: [{'runtime':'{value=20240604181205, type=class java.lang.String, identifying=true}'}]
2024-06-04T18:13:51.758+09:00  INFO 2568 --- [batchretry] [           main] o.s.batch.core.job.SimpleStepHandler     : Step already complete or not restartable, so no action to execute: StepExecution: id=1, version=null, name=step1, status=COMPLETED, exitStatus=COMPLETED, readCount=0, filterCount=0, writeCount=0 readSkipCount=0, writeSkipCount=0, processSkipCount=0, commitCount=1, rollbackCount=0, exitDescription=
2024-06-04T18:13:51.814+09:00  INFO 2568 --- [batchretry] [           main] o.s.batch.core.job.SimpleStepHandler     : Step already complete or not restartable, so no action to execute: StepExecution: id=1, version=null, name=step1, status=COMPLETED, exitStatus=COMPLETED, readCount=0, filterCount=0, writeCount=0 readSkipCount=0, writeSkipCount=0, processSkipCount=0, commitCount=1, rollbackCount=0, exitDescription=
2024-06-04T18:13:51.863+09:00  INFO 2568 --- [batchretry] [           main] o.s.b.c.l.support.SimpleJobLauncher      : Job: [SimpleJob: [name=testJob]] completed with the following parameters: [{'runtime':'{value=20240604181205, type=class java.lang.String, identifying=true}'}] and the following status: [COMPLETED] in 167ms

Thanks,

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions