StepExecution.getEndTime() returns null in StepExecutionListener.afterStep()

[HomoEfficio]

trafficstars

Bug description

StepExecution.getEndTime() invoked inside StepExecutionListener.afterStep() returns null.

It should return a valid time, according to the API docs which says below:

(StepExecutionListener.afterStep() is) Called after execution of step's processing logic (both successful or failed).

I already checked the similar isssue, https://github.com/spring-projects/spring-batch/issues/2710, but the comments in that issue do not seem to be consistent with the API docs.

Environment

Java version: AdoptOpenJDK 11 Spring Batch version: 4.3.1 Spring Boot version: 2.4.2

Steps to reproduce

Download and execute this spring boot application: https://github.com/HomoEfficio/scratchpad-spring-batch

The console result is like below:

[  restartedMain] i.h.s.s.s.SpringBatchSampleApplication   : Started SpringBatchSampleApplication in 0.812 seconds (JVM running for 1.259)
[  restartedMain] o.s.b.a.b.JobLauncherApplicationRunner   : Running default command line with: []
[  restartedMain] o.s.b.c.l.support.SimpleJobLauncher      : Job: [SimpleJob: [name=Sample Job]] launched with the following parameters: [{}]
[  restartedMain] o.s.batch.core.job.SimpleStepHandler     : Executing step: [Sample Step]
[  restartedMain] i.h.s.springbatch.sample.BatchConfig     : Sample TaskLet executed
[  restartedMain] i.h.s.springbatch.sample.BatchConfig     : stepName: Sample Step
[  restartedMain] i.h.s.springbatch.sample.BatchConfig     : stepStartedAt: Mon Feb 08 11:36:12 KST 2021
[  restartedMain] i.h.s.springbatch.sample.BatchConfig     : stepEndedAt: null  ===============> SHOULD BE A VALID TIME
[  restartedMain] o.s.batch.core.step.AbstractStep         : Step: [Sample Step] executed in 10ms
[  restartedMain] i.h.s.springbatch.sample.BatchConfig     : jobName: Sample Job
[  restartedMain] i.h.s.springbatch.sample.BatchConfig     : jobStartedAt: Mon Feb 08 11:36:12 KST 2021
[  restartedMain] i.h.s.springbatch.sample.BatchConfig     : jobEndedAt: Mon Feb 08 11:36:12 KST 2021
[  restartedMain] o.s.b.c.l.support.SimpleJobLauncher      : Job: [SimpleJob: [name=Sample Job]] completed with the following parameters: [{}] and the following status: [COMPLETED] in 21ms

Expected behavior

StepExecution.getEndTime() invoked inside StepExecutionListener.afterStep() should return a valid time instead of null.

Minimal Complete Reproducible example

https://github.com/HomoEfficio/scratchpad-spring-batch

[arun406]

is there any update on this bug. I am also facing same issue.

[fmbenhassine]

Thank you for opening this issue.

I agree, StepExecutionListener#afterStep is called after the step is finished (successfully or with a failure), so the end time should be set at that point. Moreover, this is currently not consistent with JobExecutionListener#afterJob, which is called after the end time is set (so the end time will be set when requested in the listener).

I see listeners as pre/post processing injection points, and not part of the actual job/step execution itself. A typical example for such listeners is timing a job or step, which is impossible if the end time is null in afterStep or afterJob.

This will be a minor breaking change, so I will plan it for one of the upcoming minor versions.

[Kyoungwoong]

can I take this issue?

[fmbenhassine]

@Kyoungwoong Sure. Thank you for your offer to help!