Issue
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);
});
}
}
Solution
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).
Answered By - Mahmoud Ben Hassine
Answer Checked By - Robin (JavaFixing Admin)