홈 뷰 API 응답 속도, pt-query-digest와 Sentry로 81% 개선기

유영재·2025년 4월 6일

Morib

목록 보기

2/3

이번에는 Sentry를 통해 성능 저하를 감지하고, pt-query-digest를 활용하여 병목 지점인 슬로우 쿼리를 식별하고 개선함으로써 홈 뷰 조회 API의 평균 응답 시간을 약 81%, p95 응답 시간을 약 61.78% 단축시킨 과정을 공유하고자 합니다.

🚨 Situation : 홈 뷰가 느려요

성능은 사용자 경험과 직결되기 때문에, Sentry의 APM을 활용하여 주요 API의 성능을 꾸준히 모니터링하고 있습니다.

어느 날부터 Sentry 대시보드에서 홈 뷰 조회 API의 응답 시간이 눈에 띄게 증가하는 패턴을 확인했습니다.

평균 응답 시간 (Avg): 145.86ms
p95 응답 시간: 152.99ms

평균 응답 시간도 문제지만, p95 응답 시간이 150ms를 넘는다는 것은 사용자의 5%는 홈 뷰를 로딩하는 데 0.15초 이상을 기다려야 한다는 의미였습니다. 이는 사용자 경험에 분명 영향을 미칠 수 있는 수치였고, 개선이 시급하다고 판단했습니다.

🔍 Try : pt-query-digest

Sentry를 통해 어떤 API가 문제인지는 특정했지만, 정확히 왜 느린지에 대한 답을 찾기 위해서는 더 깊은 분석이 필요했습니다. 홈 뷰는 사용자 정보, 친구 목록, 최근 활동 등 다양한 데이터를 조합하여 보여주기 때문에 데이터베이스 쿼리가 병목일 가능성이 높다고 판단했습니다.

여기서 저희가 선택한 도구는 바로 pt-query-digest입니다.
pt-query-digest는 Percona Toolkit에 포함된 도구로, MySQL의 슬로우 쿼리 로그(Slow Query Log)를 분석하여 어떤 쿼리가 가장 많은 시간을 소요했는지, 얼마나 자주 실행되었는지 등을 리포트로 보여주는 슬로우 쿼리 분석 오픈소스입니다.

분석 과정:

MySQL 슬로우 쿼리 로깅 활성화: MySQL 설정에서 슬로우 쿼리 로깅을 활성화하고, 임계 시간을 설정하여 500ms 이상 소요된 쿼리들을 기록하도록 했습니다.
```
-- my.cnf 또는 MySQL 설정에서
slow_query_log = 1
slow_query_log_file = /var/log/mysql/mysql-slow.log
long_query_time = 0.5 
```
슬로우 쿼리 로그 수집: 일정 시간 동안 서비스를 운영하며 슬로우 쿼리 로그를 수집했습니다.
pt-query-digest 실행: 수집된 슬로우 쿼리 로그 파일을 pt-query-digest로 분석했습니다.
```
pt-query-digest /var/log/mysql/mysql-slow.log > slow_query_report.txt
```
리포트 분석: 생성된 slow_query_report.txt 파일을 열어 실행 시간, 실행 횟수 등을 기준으로 상위 쿼리들을 집중적으로 분석했습니다.

🚀 Action : N+1 해결

pt-query-digest 분석 결과를 바탕으로 다음과 같은 최적화 작업을 진행했습니다.

N+1 문제 해결: 홈 뷰 로직에서 사용자 목록을 가져온 후, 각 사용자의 추가 정보를 얻기 위해 루프 내에서 개별 쿼리가 실행되는 N+1 문제가 발생하고 있었습니다. 이를 해결하기 위해 Spring Data JPA의 JOIN FETCH를 사용하여 연관된 데이터를 한 번의 쿼리로 가져오도록 수정했습니다.
```
// JOIN FETCH 활용
@Query("SELECT c FROM Category c " +
        "LEFT JOIN FETCH c.tasks t " +
        "LEFT JOIN FETCH t.timers ti " +
        "WHERE c.user.id = :userId " +
        "ORDER BY c.createdAt ASC ")
List<Category> findByUserIdAndFetchTasksAndTimers(Long userId);
```