해당 학습 내용은 [인프런] 인프라공방 - 그럴듯한 서비스 만들기 강의를 기반으로 학습한 내용을 정리한 내용입니다.
성능 테스트에 관한 기본적인 내용을 학습했으니 시나리오를 기반으로 성능 테스트를 연습해봅니다.
첫 번째 시나리오 : 회원 가입 요청 지연
요구사항
- 컨퍼런스 신청 플랫폼을 오픈했다. 사이트 접속자가 회원가입을 하는데 지연이 발생한다는 문의를 받았다.
- VUser별 iteration time이 100ms 이하여야 한다.
(1) 우선 해당 문제를 재현해보자.
먼저 지연이 발생한 증상 재현 및 원인 파악을 위해 smoke test 를 통해 테스트를 진행해봅니다. 테스트 실행 조건과 실행 결과 아래와 같습니다. smoke test 결과 average response time 이 1200ms 로 목표 iteration time 보다 10배 이상의 응답 시간으로 요청을 처리하는 것을 확인할 수 있습니다.
- 테스트 실행 조건
- VUser : 1 (1 process x 1 thread)
- 테스트 실행 시간 : 1min
- 로컬 서버 환경
- OS : macOS Sonoma ver 14.4.1
- CPU : 2.3 GHz 8코어 Intel Core i9
- Memory : 16GB 2667 MHz DDR4
- 테스트 실행 결과
- avg response time : 1200ms
- TPS : 0.9 (최고 TPS : 1.5)
- 성공 테스트 : 46 (46/46)
(2) 지연이 발생한 원인 지점을 파악해보자.
해당 증상의 원인을 파악하기 위해 pinpoint 의 call tree 를 활용해 각 클래스마다에서 처리하는 시간을 확인해보니 NotificationService.send(SendMailEvent event) 에서 요청 처리 시간의 대부분을 차지하는 것을 확인할 수 있었습니다. 해당 코드를 검토한 결과, 메일링 하는 로직에서 Thread.sleep() 로직으로 스레드를 대기시키는 로직이 포함되어 있네요.
open class Mail(
private val javaMailSender: JavaMailSender,
private val mailProperties: MailProperties
) : Notification {
override fun send(recipient: String, subject: String, contents: String) {
send(listOf(recipient), subject, contents)
}
override fun send(recipient: List<String>, subject: String, contents: String) {
check(recipient.isNotEmpty()) {
throw IllegalArgumentException("수신자가 없어 메일을 발송할 수 없습니다.")
}
delay(1000L)
}
}
fun delay(timeMills: Long) = Thread.sleep(timeMills)
추가 확인을 위해 jstack 을 통해 thread dump 를 진행하였습니다. dump 시점은 smoke test 중간 지점인 30 초 시점에 thread dump 를 진행했습니다. thread dump log 확인해보니 요청을 처리하는 tomcat thread 의 상태가 TIMED_WAITING 상태로 일시 대기하는 것을 확인했습니다. 위 내용들을 토대로 thread 대기로 코드로 인한 응답 지연인 것으로 추정하였습니다.
jstack [pid] > [thread dump 할 파일명]"http-nio-8084-exec-7" #279 [48163] daemon prio=5 os_prio=31 cpu=1217.09ms elapsed=3895.05s tid=0x00007fddc505fc00 nid=48163 waiting on condition [0x000070000b32d000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep0(java.base@21/Native Method)
at java.lang.Thread.sleep(java.base@21/Thread.java:509)
at com.brainbackdoor.support.InlineFunctionsKt.delay(InlineFunctions.kt:6)
at com.brainbackdoor.notifications.Mail.send(Mail.kt:24)
at com.brainbackdoor.notifications.Mail.send(Mail.kt:16)
at com.brainbackdoor.notifications.NotificationService.send(NotificationService.kt:17)
at com.brainbackdoor.members.application.MemberService.create(MemberService.kt:30)
(3) 이제 개선해보자.
가장 간단한 방법은 thread 를 TIMED_WATING 하는 로직을 제거하는 방법이지만 메일을 전송한다는 전제로 작성된 로직이기 때문에 해당 로직을 제거하지 않는 방법으로 개선할 방법을 고민했습니다. 문제의 원인은 메일을 전송 완료 시점까지 스레드가 대기한다는 점이었습니다. 이 근본 원인을 해결하기 위해 고민한 방법은 EventPublisher, @Async 어노테이션 입니다.
하지만 EventPublisher 를 활용하는 방법은 이벤트를 발행하더라도 같은 스레드로 이벤트를 처리하기 때문에 해당 원인을 해결할 수 있는 방법이 아니었습니다. 결국, @Async 어노테이션을 통해 메일 전송하는 로직을 별도의 스레드로 할당하는 방법을 선택했습니다. 해당 방법을 활용할 경우 메일 전송하는 로직을 다른 스레드가 처리하는 과정에서 응답 결과를 반환할 수 있습니다.
다시 smoke test 를 통해 결과를 확인해보면 기존 1100ms → 176ms 로 개선된 것을 확인했습니다. 목표 iteration time 에 미치지 못하지만 응답 시간이 근사치에 가까운 결과를 반환하는 점에서 유의미한 개선 요소인 것으로 판단됩니다. 추가 개선 사항을 파악하면 추가 개선에 관한 내용을 정리해보겠습니다!
