spring-batch icon indicating copy to clipboard operation
spring-batch copied to clipboard

Log messages inside the constructor of scoped bean could be ignored.

Open umbum opened this issue 3 years ago • 0 comments
trafficstars

Bug description When the uninitialized scoped bean is passed to slf4j log method, log messages inside the constructor of scoped bean are ignored.

Environment

org.springframework.boot:spring-boot-starter-batch:2.7.2
org.springframework.batch:spring-batch-core:4.3.6
org.springframework.boot:spring-boot-starter-logging:2.7.2
ch.qos.logback:logback-classic:1.2.11
org.apache.logging.log4j:log4j-to-slf4j:2.17.2
org.slf4j:jul-to-slf4j:1.7.36

Steps to reproduce Minimal Complete Reproducible example

@Slf4j
@RequiredArgsConstructor
@Configuration
public class SimpleJobConfig {
    private final JobBuilderFactory jobBuilderFactory;
    private final StepBuilderFactory stepBuilderFactory;
    private final JobScopedBeanA jobScopedBeanA;
    private final JobScopedBeanB jobScopedBeanB;

    @Bean
    public Job simpleJob() {
        return jobBuilderFactory.get("simpleJob")
            .start(simpleStep1())
            .build();
    }

    @Bean
    public Step simpleStep1() {
        return stepBuilderFactory.get("simpleStep1")
            .tasklet((contribution, chunkContext) -> {
                log.info(">>>>> This is Step1 {}", jobScopedBeanA);
                log.info(">>>>> This is Step1 {}", jobScopedBeanB.toString());
                return RepeatStatus.FINISHED;
            })
            .build();
    }
}
@Slf4j
@JobScope
@Component
@Getter
@ToString
public class JobScopedBeanA {
    private final String fieldA;

    public JobScopedBeanA() {
        this.fieldA = "fieldA";
        log.info("### meta:fieldA {}", fieldA);
    }
}

@Slf4j
@JobScope
@Component
@Getter
@ToString
public class JobScopedBeanB {
    private final String fieldB;

    public JobScopedBeanB() {
        this.fieldB = "fieldB";
        log.info("### meta:fieldB {}", fieldB);
    }
}

result

2022-07-27 16:10:48.643  INFO 12908 --- [  restartedMain] o.s.batch.core.job.SimpleStepHandler     : Executing step: [simpleStep1]
2022-07-27 16:10:48.647  INFO 12908 --- [  restartedMain] c.example.batchlogtest.SimpleJobConfig   : >>>>> This is Step1 JobScopedBeanA(fieldA=fieldA)
2022-07-27 16:10:48.648  INFO 12908 --- [  restartedMain] com.example.batchlogtest.JobScopedBeanB  : ### meta:fieldB fieldB
2022-07-27 16:10:48.648  INFO 12908 --- [  restartedMain] c.example.batchlogtest.SimpleJobConfig   : >>>>> This is Step1 JobScopedBeanB(fieldB=fieldB)
2022-07-27 16:10:48.652  INFO 12908 --- [  restartedMain] o.s.batch.core.step.AbstractStep         : Step: [simpleStep1] executed in 9ms

Expected behavior ### meta:fieldA fieldA have to be printed.

umbum avatar Jul 30 '22 00:07 umbum