Home > OS >  Spring Batch When I run using joblauncher, I think the job is not running
Spring Batch When I run using joblauncher, I think the job is not running

Time:08-24

If I restart the project, the job I registered works well and the log is taken well.

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.7.2)

2022-08-23 05:07:50.729  INFO 16360 --- [  restartedMain] c.capston.chatting.ChattingApplication   : Starting ChattingApplication using Java 11.0.12 on DESKTOP-SHB62PK with PID 16360 (D:\chatting\chatting\build\classes\java\main started by user in D:\chatting\chatting)
2022-08-23 05:07:50.730  INFO 16360 --- [  restartedMain] c.capston.chatting.ChattingApplication   : The following 4 profiles are active: "google", "naver", "kakao", "local"
2022-08-23 05:07:50.753  INFO 16360 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable
2022-08-23 05:07:50.753  INFO 16360 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG'
2022-08-23 05:07:51.120  INFO 16360 --- [  restartedMain] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-08-23 05:07:51.152  INFO 16360 --- [  restartedMain] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 28 ms. Found 4 JPA repository interfaces.
2022-08-23 05:07:51.470  INFO 16360 --- [  restartedMain] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-08-23 05:07:51.474  INFO 16360 --- [  restartedMain] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-08-23 05:07:51.475  INFO 16360 --- [  restartedMain] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.65]
2022-08-23 05:07:51.547  INFO 16360 --- [  restartedMain] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-08-23 05:07:51.547  INFO 16360 --- [  restartedMain] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 794 ms
2022-08-23 05:07:51.595  INFO 16360 --- [  restartedMain] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-08-23 05:07:51.738  INFO 16360 --- [  restartedMain] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-08-23 05:07:51.793  INFO 16360 --- [  restartedMain] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-08-23 05:07:51.814  INFO 16360 --- [  restartedMain] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.6.10.Final
2022-08-23 05:07:51.889  INFO 16360 --- [  restartedMain] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2022-08-23 05:07:51.939  INFO 16360 --- [  restartedMain] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.MySQL8Dialect
2022-08-23 05:07:52.204  INFO 16360 --- [  restartedMain] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-08-23 05:07:52.208  INFO 16360 --- [  restartedMain] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-08-23 05:07:52.636  INFO 16360 --- [  restartedMain] o.s.s.web.DefaultSecurityFilterChain     : Will secure any request with [org.springframework.security.web.session.DisableEncodeUrlFilter@62239b45, org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@3596673e, org.springframework.security.web.context.SecurityContextPersistenceFilter@49f2b09c, org.springframework.security.web.header.HeaderWriterFilter@576fbb11, org.springframework.security.web.authentication.logout.LogoutFilter@2356ea3a, org.springframework.security.web.authentication.UsernamePasswordAuthenticationFilter@378ce71, org.springframework.security.web.session.ConcurrentSessionFilter@fac8000, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@704795de, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@41def366, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@36aed9df, org.springframework.security.web.session.SessionManagementFilter@280ea7a9, org.springframework.security.web.access.ExceptionTranslationFilter@32ddfe1, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@74600b37]
2022-08-23 05:07:52.641  INFO 16360 --- [  restartedMain] c.c.c.c.batch.InactiveMemberJobConfig    : InactiveMemberJob execution
2022-08-23 05:07:52.641  INFO 16360 --- [  restartedMain] c.c.c.c.batch.InactiveMemberJobConfig    : InactiveMemberStep execution
2022-08-23 05:07:52.642  INFO 16360 --- [  restartedMain] c.c.c.c.batch.InactiveMemberJobConfig    : InactiveMemberReader execution
2022-08-23 05:07:52.660 DEBUG 16360 --- [  restartedMain] org.hibernate.SQL                        : 
    select
        member0_.member_id as member_i1_3_,
        member0_.created_date as created_2_3_,
        member0_.update_date as update_d3_3_,
        member0_.login_id as login_id4_3_,
        member0_.login_pw as login_pw5_3_,
        member0_.name as name6_3_,
        member0_.role as role7_3_,
        member0_.score as score8_3_,
        member0_.status as status9_3_ 
    from
        member member0_ 
    where
        member0_.update_date<? 
        and member0_.status=?
2022-08-23 05:07:52.699  INFO 16360 --- [  restartedMain] c.c.c.c.batch.InactiveMemberJobConfig    : test
2022-08-23 05:07:52.699  INFO 16360 --- [  restartedMain] c.c.c.c.batch.InactiveMemberJobConfig    : InactiveMemberWriter execution
2022-08-23 05:07:52.826  WARN 16360 --- [  restartedMain] o.s.b.a.batch.JpaBatchConfigurer         : JPA does not support custom isolation levels, so locks may not be taken when launching Jobs. To silence this warning, set 'spring.batch.jdbc.isolation-level-for-create' to 'default'.
2022-08-23 05:07:52.828  INFO 16360 --- [  restartedMain] o.s.b.c.r.s.JobRepositoryFactoryBean     : No database type set, using meta data indicating: MYSQL
2022-08-23 05:07:52.835  INFO 16360 --- [  restartedMain] o.s.b.c.l.support.SimpleJobLauncher      : No TaskExecutor has been set, defaulting to synchronous executor.
2022-08-23 05:07:52.912  INFO 16360 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2022-08-23 05:07:52.933  INFO 16360 --- [  restartedMain] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-08-23 05:07:52.934  INFO 16360 --- [  restartedMain] o.s.m.s.b.SimpleBrokerMessageHandler     : Starting...
2022-08-23 05:07:52.935  INFO 16360 --- [  restartedMain] o.s.m.s.b.SimpleBrokerMessageHandler     : BrokerAvailabilityEvent[available=true, SimpleBrokerMessageHandler [org.springframework.messaging.simp.broker.DefaultSubscriptionRegistry@25358374]]
2022-08-23 05:07:52.935  INFO 16360 --- [  restartedMain] o.s.m.s.b.SimpleBrokerMessageHandler     : Started.
2022-08-23 05:07:52.941  INFO 16360 --- [  restartedMain] c.capston.chatting.ChattingApplication   : Started ChattingApplication in 2.426 seconds (JVM running for 2.944)
2022-08-23 05:07:52.942  INFO 16360 --- [  restartedMain] o.s.b.a.b.JobLauncherApplicationRunner   : Running default command line with: []
2022-08-23 05:07:53.327  INFO 16360 --- [  restartedMain] o.s.b.c.l.support.SimpleJobLauncher      : Job: [SimpleJob: [name=inactiveMemberJob3]] launched with the following parameters: [{}]
2022-08-23 05:07:53.617  INFO 16360 --- [  restartedMain] o.s.batch.core.job.SimpleStepHandler     : Executing step: [inactiveMemberStep]
2022-08-23 05:07:53.811  INFO 16360 --- [  restartedMain] o.s.batch.core.step.AbstractStep         : Step: [inactiveMemberStep] executed in 194ms
2022-08-23 05:07:53.964  INFO 16360 --- [  restartedMain] o.s.b.c.l.support.SimpleJobLauncher      : Job: [SimpleJob: [name=inactiveMemberJob3]] completed with the following parameters: [{}] and the following status: [COMPLETED] in 565ms

However, when I try to run using joblauncher, there is no log registered in job and only the log corresponding to job start and step start.

2022-08-23 05:08:13.746  INFO 16360 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-08-23 05:08:13.746  INFO 16360 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-08-23 05:08:13.747  INFO 16360 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 1 ms
2022-08-23 05:08:14.015  INFO 16360 --- [nio-8080-exec-1] o.s.b.c.l.support.SimpleJobLauncher      : Job: [SimpleJob: [name=inactiveMemberJob3]] launched with the following parameters: [{}]
2022-08-23 05:08:14.271  INFO 16360 --- [nio-8080-exec-1] o.s.batch.core.job.SimpleStepHandler     : Executing step: [inactiveMemberStep]
2022-08-23 05:08:14.458  INFO 16360 --- [nio-8080-exec-1] o.s.batch.core.step.AbstractStep         : Step: [inactiveMemberStep] executed in 187ms
2022-08-23 05:08:14.607  INFO 16360 --- [nio-8080-exec-1] o.s.b.c.l.support.SimpleJobLauncher      : Job: [SimpleJob: [name=inactiveMemberJob3]] completed with the following parameters: [{}] and the following status: [COMPLETED] in 526ms
2022-08-23 05:08:14.607  INFO 16360 --- [nio-8080-exec-1] c.c.chatting.controller.HomeController   : IsRunning : false
2022-08-23 05:08:52.572  INFO 16360 --- [MessageBroker-1] o.s.w.s.c.WebSocketMessageBrokerStats    : WebSocketSession[0 current WS(0)-HttpStream(0)-HttpPoll(0), 0 total, 0 closed abnormally (0 connect failure, 0 send limit, 0 transport error)], stompSubProtocol[processed CONNECT(0)-CONNECTED(0)-DISCONNECT(0)], stompBrokerRelay[null], inboundChannel[pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0], outboundChannel[pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0], sockJsScheduler[pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]

I debugged the run method in the joblauncher, and the incoming values were the same as they were when they were restarted.

Is there anything i'm missing?

HomeController.java

package com.capston.chatting.controller;

import com.capston.chatting.config.batch.InactiveMemberJobConfig;
import com.capston.chatting.dto.GetRoomIdDto;
import com.capston.chatting.entity.ChatRoom;
import com.capston.chatting.entity.Member;
import com.capston.chatting.repository.MemberRepository;
import com.capston.chatting.service.ChatRoomService;
import lombok.RequiredArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.springframework.batch.core.JobExecution;
import org.springframework.batch.core.JobParameters;
import org.springframework.batch.core.launch.JobLauncher;
import org.springframework.stereotype.Controller;
import org.springframework.ui.Model;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.ResponseBody;

import javax.servlet.http.HttpSession;
import java.util.*;

@Controller
@RequiredArgsConstructor
@Slf4j
public class HomeController {
    // Test
    private final JobLauncher jobLauncher;
    private final InactiveMemberJobConfig config;

    @GetMapping("/job_start")
    @ResponseBody
    public String jobStart() {
        JobExecution run = null;
        try {
            run = jobLauncher.run(config.inactiveMemberJob(), new JobParameters());
            log.info("IsRunning : {}", run.isRunning());
        } catch (Exception e) {
            log.error(e.getMessage());
        }

        return String.valueOf(run.getJobInstance());
    }
}

InactiveMemberJobConfig.java

package com.capston.chatting.config.batch;

import com.capston.chatting.entity.Member;
import com.capston.chatting.enums.MemberStatus;
import com.capston.chatting.repository.MemberRepository;
import lombok.RequiredArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.springframework.batch.core.Job;
import org.springframework.batch.core.Step;
import org.springframework.batch.core.configuration.annotation.JobBuilderFactory;
import org.springframework.batch.core.configuration.annotation.StepBuilderFactory;
import org.springframework.batch.item.ItemProcessor;
import org.springframework.batch.item.ItemWriter;
import org.springframework.batch.item.support.ListItemReader;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

import java.time.LocalDateTime;
import java.util.List;

@Slf4j
@RequiredArgsConstructor
@Configuration
public class InactiveMemberJobConfig {

    private final MemberRepository memberRepository;
    private final JobBuilderFactory jobBuilderFactory;
    private final StepBuilderFactory stepBuilderFactory;

    @Bean
    public Job inactiveMemberJob() {
        log.info("InactiveMemberJob execution");
        return jobBuilderFactory.get("inactiveMemberJob3")
                .start(inactiveJobStep())
                .build();
    }

    @Bean
    public Step inactiveJobStep() {
        log.info("InactiveMemberStep execution");
        return stepBuilderFactory.get("inactiveMemberStep")
                .<Member, Member>chunk(10)
                .reader(inactiveMemberReader())
                .processor(inactiveMemberProcessor())
                .writer(inactiveMemberWriter())
                .allowStartIfComplete(true)
                .build();
    }

    @Bean
    public ListItemReader<Member> inactiveMemberReader() {
        log.info("InactiveMemberReader execution");
        List<Member> oldMembers = memberRepository
                .findByUpdateDateBeforeAndStatusEquals(LocalDateTime.now().minusYears(1), MemberStatus.ACTIVE);

//        ArrayList<Member> collect = oldMembers.stream().map(member -> member.setInactive()).collect(Collectors.toCollection(ArrayList::new));
//        memberRepository.saveAll(collect);
        return new ListItemReader<>(oldMembers);
    }

    @Bean
    public ItemProcessor<Member, Member> inactiveMemberProcessor() {
        log.info("test");
        ItemProcessor<Member, Member> memberItemProcessor = (member) -> {
            log.info("InactiveMemberProcessor execution");
            return member.setInactive();
        };
        return memberItemProcessor;
//        return new ItemProcessor<Member, Member>() {
//            @Override
//            public Member process(Member member) throws Exception {
//                log.info("InactiveMemberProcessor execution");
//                return member.setInactive();
//            }
//        };
//        return member -> {
//            log.info("InactiveMemberProcessor execution");
//            return member.setInactive();
//        };
    }

    @Bean
    public ItemWriter<Member> inactiveMemberWriter() {
        log.info("InactiveMemberWriter execution");
        return ((List<? extends Member> members) -> {
            memberRepository.saveAll(members);
            log.info("Members : {}", members);
        });
    }
}

CodePudding user response:

The default bean scope in Spring is singleton. This means that your job/step/reader/processor/writer beans will only be loaded once at application startup, and reused when requested during your application lifetime.

So the logs you defined in your bean definition methods like the following:

    @Bean
    public Job inactiveMemberJob() {
        log.info("InactiveMemberJob execution");
        // ...
    }

will only be printed when that bean definition is loaded, ie when the Spring application context starts for the first time. Now since you have a web application, that application context is not refreshed on each web request, so those bean definitions will only be loaded once. That's why you see those logs when you first start your app, but not afterwards (unless you restart your application).

  • Related