[COGO] 프로파일러와 VisualVM, 비동기처리와 스레드풀

hwee·2024년 7월 11일
0

COGO개발과정

목록 보기
8/12

세줄 요약

  1. 스레드 대기 시간이 긴 작업은 비동기 처리를 해도 좋다.
  2. spring 비동기 작업은 AOP를 기반으로 하기 때문에, 프록시가 요청을 가로채 수행한다.
  3. 비동기 작업과 트랜잭션의 메인 스레드는 서로 영향을 미치면 안된다.
  4. 메시지 큐를 활용해 비동기 처리를 AWS 아키텍처에 위임한 후, 메일 전송에 실패하면 재전송되도록 SQS, SES를 활용하여 안정성을 보완하였다. (다음 포스트)

문제 상황

인텔리제이에서 제공하는 프로파일러로 회원가입 - 멘토 검색 - 커피챗 가능 시간대 검색 - 커피챗 신청 의 로직을 수행한 후 측정하여 보니, 커피챗 신청이 완료된 후 멘티와 멘토측에 메일이 보내지는 기능의 수행 시간이 매우 길었다.
Async Profiler와 인텔리제이의 프로파일러는 reference를 참고해 공부하였다.
또한, JVM에 관해서는 reference를 참고해 공부하였다.

프로파일러 측정 결과

1. CPU Time


CPU를 점유하고 있는 시간대를 보면 createApplication(커피챗 신청)기능과 getMentorListByPart(멘토 리스트 검색)기능이 가장 많은 점유율을 가지고 있는데, 실질적으로 CPU 점유 시간이 절대적으로 큰 수치는 나오지 않았다.

위의 사진과 같이 150ms로 체감될 정도의 시간이 아니지만, 실제로 응답이 돌아오는 시간은 매우 오래 걸렸으므로 total time을 측정해 보았다.

2. Total time


성사된 커피챗의 정보를 멘토와 멘티의 이메일로 보내는데 무려 3초 이상으로 측정되었다...
그 중에서도 어느 메소드에서 가장 많은 시간을 가지고 있는지 찾아보니,

sendMail이라는 메일 자체를 보내는 기능에서 3초를 끌고 있다는 사실을 알 수 있다.
그렇다면 회원가입시 확인 이메일을 보낼 때도 문제가 생기고, 앞으로 이메일을 보내는 기능이 더 있다면 계속하여 문제가 될 것이다.
더 자세히 알아보기 위하여 VisualVM으로 스레드를 어느정도 잡고 있는지 알아보았다.

VisualVM 스레드 측정

먼저, 측정을 편하게 하고자 메일을 보내는 메소드의 시작 전후에 1초간 스레드를 쉬도록 설정하였다.
VisualVM은 referene를 참고하여 공부했다.

public void sendMail(String receiver, String subject, String content) throws MessagingException, InterruptedException {
		Thread.sleep(1000);
		MimeMessage message = javaMailSender.createMimeMessage();
		message.setSubject(subject);
		message.addRecipients(Message.RecipientType.TO, receiver);
		message.setText(content, "utf-8", "html");
		javaMailSender.send(message);
		Thread.sleep(1000);
	}

스레드 측정 결과

(스레드가 10개인 것은 작업 환경인 맥북에어 m2의 코어가 10개이기 때문이다)

6번에서 커피챗 가능 시간대를 불러온 후, 5번에서 메일을 보내는데 긴 시간을 보낸 후, 메인 스레드로 복귀하여 응답을 하므로 메일을 완전히 다 보낸 후에 응답을 보내는 상황이다.
메일을 보내는 시간 자체는 줄이기 어려우므로, 메일 보내는 기능을 비동기로 처리한 후, 빠르게 응답을 반환하는 방향으로 수정하기로 결정하였다.

비동기 처리

먼저, 내 애플리케이션이 실행되는 서버의 환경은 T2.micro로 단일 코어이기 때문에 비동기 기능을 처리하는 스레드의 기본 수는 1개로 설정하였다.
스레드풀의 설정은 reference를 참고하여 공부하였다.

비동기 기능 처리 스레드풀 설정

@Configuration
public class AsyncConfig {
    @Bean(name = "mailExecutor")
    public Executor mailExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(1);  // 기본 스레드 수
        executor.setMaxPoolSize(2);   // 최대 스레드 수
        executor.setQueueCapacity(50);  // 큐 용량
        executor.setThreadNamePrefix("MailExecutor-");  // 스레드 이름 접두사
        executor.initialize();
        return executor;
    }
}

비즈니스 로직 수정

@Transactional
	public ApplicationCreateResponse createApplication(ApplicationCreateRequest request, String userName) throws Exception {
		...생략...
		// 비동기 메일 발송 메서드를 프록시를 통해 호출
		ApplicationService proxy = applicationContext.getBean(ApplicationService.class);
		proxy.sendApplicationMatchedEmailAsync(findMenteeUser.getEmail(), findMentorUser.getName(),
				findMenteeUser.getName(), savedApplication.getDate(), savedApplication.getStartTime(),
				savedApplication.getEndTime());
		return ApplicationCreateResponse.from(savedApplication);
	}
	@Async("mailExecutor")
	public void sendApplicationMatchedEmailAsync(String email, String mentorName, String menteeName, LocalDate date, LocalTime startTime, LocalTime endTime) throws MessagingException, InterruptedException {
		emailUtil.sendApplicationMatchedEmail(email, mentorName, menteeName, date, startTime, endTime);
	}

프록시를 생성하여 해당 프록시에서 비동기 작업을 실행하게 수정하였는데,이는 2가지의 이유가 존재한다.
1. 비동기 작업은 AOP를 기반으로 하므로, @Async 어노테이션이 붙은 메서드는 프록시를 통해서 실행된다.
2. 비동기 작업은 트랜잭션의 커밋이나 롤백에 영향을 받으면 안되므로, 트랜잭션이 종료되고 비동기 작업이 실행될 수 있도록 비동기 작업을 트랜잭션 외부로 뺀다.

비동기 처리와 AOP에 대해서는 reference를 참고해 공부하였다.

재측정

프로파일러 CPU Burst 측정 결과



원래도 CPU점유 시간은 적었지만, 더 적어진 110ms로 CPU Burst time이 150ms->110ms로 단축되었다.

프로파일러 Total Time 측정 결과


정말 엄청나게 줄었다.
3661ms에서 120ms면 무려 30배가량 응답 속도가 빨라진 효과를 볼 수 있었다.

(위의 측정 결과는 이메일을 보내기 직전과 직후 1초씩 스레드를 sleep시켜놓은 상태로, 2초가량 제하고 생각해야 한다.)
변경한 비즈니스 로직을 봐도, 메일 보내는 기능 자체를 비동기 작업으로 빼놓고 실행이 된 것을 알 수 있다.
물론 메일을 보내는 데는 아직도 3~4초가량 걸리지만, 3~4초간 응답이 가지 않아 클라이언트의 화면에서 그 시간동안 아무 응답이 없는 상황에 비하면 훨씬 개선되었다고 할 수 있다.

VisualVM 측정 결과


위에서 비동기작업 용으로 생성한 스레드풀(MailExecutor)에서 대기하고 있던 스레드가 실행되는 것을 볼 수 있다.
즉, 해당 스레드가 실행되기 직전에 요청에 대한 응답이 반환된 것이다.

최종 결과

기존의 로직에서 커피챗을 신청하면 응답이 가는 데에 4초가량이 걸려 클라이언트에게 서비스가 멈춰있는 현상을 프로파일러와 VisualVM을 통해 분석하였고, 비동기 처리를 통해 해결하였다.
이제 커피챗을 신청하면 120ms(0.1초)만에 응답이 가므로 비교적 훨씬 수월한 사용감을 클라이언트에게 제공할 수 있게 되었다.

profile
화이팅!

0개의 댓글