[Moment] 프로젝트 쿼리 실행속도 50초 단축하기

왜? 쿼리 성능을 측정 해야할까?

서비스는 성장하고 데이터는 계속 쌓인다.
지금의 쿼리 구조가 미래의 대용량 데이터 환경에서도 최적의 성능을 보장할 수 있는지 검증할 필요가 있었다.
문제가 발생한 뒤에 대응하는 것은 늦다.

이 글은 프로젝트에서 정확한 쿼리 실행 시간을 측정하고, 쿼리 지연 문제를 해결하는 과정을 기록했다.

 

쿼리 속도 측정하기

1. AOP

AOP 를 사용하여 Repository 실행시간을 측정하면 쿼리실행 속도를 완전히 측정할 수 있을까?

1. 측정 범위가 너무 넓다: AOP는 메서드 호출 시작부터 끝까지를 측정하기 때문에, 순수 쿼리 실행 시간 외에
    커넥션 획득/반납, 네트워크 지연, 결과 변환(매핑) 등의 부가적인 시간이 모두 포함된다.

2. 개별 쿼리 분석이 불가능하다: 하나의 메서드에서 여러 쿼리가 실행될 경우,
    각 쿼리의 시간을 분리해서 볼 수 없고 전체 합산된 시간만 알 수 있다.

2. p6spy

2025-09-15 17:39:50.340 [Test worker] INFO  p6spy - #1757925590340 | took 0ms | statement | connection 0| url jdbc:h2:mem:b75e0ae4-912c-484b-acd8-79ed1a10c94b
select * 
from "PUBLIC"."flyway_schema_history" for update;
2025-09-15 17:39:50.340 [Test worker] INFO  p6spy - #1757925590340 | took 0ms | statement | connection 0| url jdbc:h2:mem:b75e0ae4-912c-484b-acd8-79ed1a10c94b
INSERT INTO "PUBLIC"."flyway_schema_history" 
	("installed_rank", "version", "description", "type", 
         "script", "checksum", "installed_by", "execution_time", "success") 
VALUES (9, '10', 'alter all except refresh tokens  h2', 'SQL', 'V10__alter_all_except_refresh_tokens__h2.sql', -1747148076, 'SA', 7, true);

p6spy는 DBC 드라이버를 감싸는 프록시(Proxy)로 동작하여,
애플리케이션과 데이터베이스 사이를 오가는 SQL문을 직접 가로채서 분석한다. 

덕분에 AOP 방식보다 훨씬 더 순수한 쿼리 실행 시간을 개별적으로 측정하고,

파라미터가 바인딩된 완성된 쿼리문을 확인할 수 있어 성능 분석을 가능하게 해준다.

테스트 데이터 생성하기

dependencies {
    // 테이스 데이터를 쉽게 생성
    implementation 'com.github.javafaker:javafaker:1.0.2'
    // csv 파일을 생성
    implementation 'com.opencsv:opencsv:5.9'

    testImplementation platform('org.junit:junit-bom:5.10.0')
    testImplementation 'org.junit.jupiter:junit-jupiter'
}

1. Javafaker + CSV 파일 생성

p6spy를 통해 쿼리 실행 시간을 정확하게 측정할 준비가 되었다.
하지만 의미 있는 성능 개선을 위해서는 실제 운영 환경과 유사한 대용량 데이터가 필요하다.

대용량 데이터를 생성, 추가하는 방법은 여러가지가 있지만,

가장 빠르고 업로드 부담이 없는 CSV 파일을 업로드 하는 방식을 사용하기로 했다.

 

javafaker는 더미데이터를 쉽게 생성하기위한 기능을 제공한다.

opencsv는 javafaker로 생성한 더미데이터들을 쉽게 CSV 파일로 변환해준다.

문제 쿼리 

-- 1단계 코멘트 조회 (코멘트가 가진 모멘트, 코멘트 작성자 함께 조회) 40초 소요 (문제의 쿼리)
took 40,732ms (40초)
select c1_0.id, c1_0.commenter_id, ... 
from comments c1_0 
join moments m1_0 on m1_0.id=c1_0.moment_id 
join users m2_0 on m2_0.id=m1_0.momenter_id 
where (c1_0.deleted_at IS NULL) and c1_0.commenter_id=1 
order by c1_0.created_at desc, c1_0.id desc limit 11;

1000만건 정도의 데이터를 넣으니,

코멘트 조회에서 33초 이상이 걸리는 것을 확인 할 수 있다.

왜 이렇게 오랜 시간이 걸리는 걸까?

EXPLAIN ANALYZE

EXPLAIN ANALYZE  MySql 명령어를 사용하면 문제의 쿼리의 실행 로그를 살펴볼 수 있다.

Limit: 11 row(s)  (actual time=54650..54650 rows=11 loops=1)
 -> Sort: c1_0.created_at DESC, c1_0.id DESC, limit input to 11 row(s) per chunk  (actual time=54650..54650 rows=11 loops=1)
   -> Stream results  (cost=169747 rows=604) (actual time=315..54535 rows=82940 loops=1)
       -> Nested loop inner join  (cost=169747 rows=604) (actual time=315..54282 rows=82940 loops=1)
           -> Nested loop inner join  (cost=55105 rows=12079) (actual time=0.382..6584 rows=921526 loops=1)
               -> Filter: (m2_0.deleted_at is null)  (cost=10.6 rows=10.3) (actual time=0.0419..0.459 rows=103 loops=1)
                   -> Table scan on m2_0  (cost=10.6 rows=103) (actual time=0.0399..0.37 rows=103 loops=1)
               -> Filter: (m1_0.deleted_at is null)  (cost=4188 rows=1173) (actual time=0.625..63.2 rows=8947 loops=103)
                   -> Index lookup on m1_0 using fk_moments_users (momenter_id=m2_0.id)  (cost=4188 rows=11727) (actual time=0.625..62 rows=9418 loops=103)
           -> Filter: ((c1_0.commenter_id = 1) and (c1_0.deleted_at is null))  (cost=8.48 rows=0.05) (actual time=0.0498..0.0516 rows=0.09 loops=921526)
               -> Index lookup on c1_0 using fk_comments_moments (moment_id=m1_0.id)  (cost=8.48 rows=10.1) (actual time=0.0265..0.0506 rows=9.5 loops=921526)

분석을위해 쿼리를 실행하니, 54초라는 뜨악한 시간이 걸린것을 확인할 수 있다.

actual time=54650..54650: 쿼리 총 실행 시간이 54,650ms, 즉 54.6초나 걸렸다.

rows=82940 (Stream results): 정렬(Sort) 작업 직전에 82,940개의 로우가 생성된다. 필요한 데이터는 단 11개인데..

loops=921526 (Index lookup on c1_0): 가장 안쪽의 c1_0 (comments 테이블)조회작업이 921,526번이나 반복된다.

1. 쿼리는 m2_0 테이블(사용자 그룹)에서 103개의 로우를 가져 온다.

Table scan on m2_0  (cost=10.6 rows=103) (actual time=0.0399..0.37 rows=103 loops=1)

2. m2_0(사용자)과 m1_0(모멘트)을 조인하면서 921,526개의 중간 결과가 생성된다.

Stream results  (cost=169747 rows=604) (actual time=315..54535 rows=82940 loops=1)

3. 92만건이 넘는 중간 결과 각각에 대해 c1_0(코멘트) 테이블을 조회한 후, commenter_id = 1 이라는 필터 조건을 적용한다.

Limit: 11 row(s)  (actual time=54650..54650 rows=11 loops=1)

인덱스

해당 쿼리가 엄청난 비효율이 있다는 것을 알았다. 

해결하기 위해서 '복합 인덱스'를 도입하기로 했다.

 

DB는 옵티마이저를 통해 최적의 실행 결과를 탐색한다.
이때 인덱스가 있다면, 옵티마이저는 최적의 속도로 데이터를 탐색할 수 있게된다.
인덱스의 원리 참고

 

해당 쿼리를 다시보자.

인덱스를 설정할때 '어떻게 탐색범위를 줄일것인가?'를 고민해야한다.

select c1_0.id, c1_0.commenter_id, ... 
from comments c1_0 
join moments m1_0 on m1_0.id=c1_0.moment_id 
join users m2_0 on m2_0.id=m1_0.momenter_id 
where (c1_0.deleted_at IS NULL) and c1_0.commenter_id=1 
order by c1_0.created_at desc, c1_0.id desc limit 11;​

그러기 위해서는 두가지가 필요하다

• WHERE 조건: commenter_id와 deleted_at
• ORDER BY 조건: created_at DESC, id DESC

where절은 탐색범위를 극적으로 줄일 수 있게한다. 위의 쿼리도 commenter_id가 1인 경우를 가장 먼저 고려했다면,

모든 유저의 코멘트를 조인하지 않아도 됐을 것이다. where절 , order by 절 순서대로 복합인덱스를 추가했다.

CREATE INDEX idx_comments_commenter_created_id
ON comments (commenter_id, deleted_at, created_at DESC, id DESC);

1. where절 , order by절 순서는 왜 중요할까?

인덱스에서 컬럼의 순서는 '어떤 순서로 데이터를 찾아갈 것인가' 를 결정한다.
WHERE절의 조건 컬럼을 앞에 두어 탐색 범위를 먼저 좁히고,

ORDER BY절의 컬럼을 뒤에 두어 불필요한 정렬 작업을 생략하는 것이 최적의 성능을 내는 방법이다.

 

만약 순서가 뒤바뀌어 (created_at, commenter_id, ...)로 인덱스를 만들었다면,

데이터베이스는 모든 댓글을 시간순으로 정렬한 뒤, 그 안에서 commenter_id가 1인 것을 하나하나 찾아야 한다.

이는 훨씬 비효율적인 방식이 된다.

2. 왜 단일 인덱스가 아닌 복합인덱스인가?

단일 인덱스를 만들었다면, 옵티마이저는 보통 하나의 인덱스만 선택해서 사용해야 하는 딜레마에 빠지게 된다.

commenter_id 인덱스를 선택한 경우, commenter_id가 1인 댓글은 빠르게 찾을 수 있다.

하지만 이 결과는 시간순으로 정렬되어 있지 않으므로,

찾아낸 데이터를 전부 메모리에 올린 후 별도로 정렬(Sort)해야 한다.

created_at 인덱스를 선택한 경우, 모든 댓글이 시간순으로 정렬되어 있으니 별도의 정렬은 필요 없다.

하지만 commenter_id가 1인 댓글을 찾기 위해 모든 댓글을 처음부터 훑어야 한다.

 

복합 인덱스는 여러 컬럼을 묶어 하나의 거대한, 잘 정렬된 전화번호부처럼 작동한다.
따라서 옵티마이저는 이 복합 인덱스 하나만으로 찾는 작업(Seeking)과

정렬된 순서대로 읽는 작업(Scanning)을 동시에, 매우 효율적으로 처리할 수 있게 된다.

쿼리 분리

인덱스를 통해 쿼리 최적화가 완료되었다고 생각했다.

하지만 인덱스를 설정했는데도, 옵티마이저가 인덱스를 선택하지 않는 문제가 발생했다.

옵티마이저가 인덱스를 선택하는 경우,

-> Limit: 11 row(s)  (cost=170490 rows=11) (actual time=0.735..0.808 rows=11 loops=1)
  -> Nested loop inner join  (cost=170490 rows=193) (actual time=0.734..0.806 rows=11 loops=1)
      -> Nested loop inner join  (cost=169816 rows=1926) (actual time=0.725..0.777 rows=11 loops=1)
          -> Filter: (c1_0.deleted_at is null)  (cost=154302 rows=19258) (actual time=0.709..0.714 rows=11 loops=1)
              -> Index lookup on c1_0 using idx_comments_commenter_created_id (commenter_id=1)  (cost=154302 rows=192576) (actual time=0.708..0.712 rows=12 loops=1)
          -> Filter: (m1_0.deleted_at is null)  (cost=0.706 rows=0.1) (actual time=0.00542..0.00549 rows=1 loops=11)
              -> Single-row index lookup on m1_0 using PRIMARY (id=c1_0.moment_id)  (cost=0.706 rows=1) (actual time=0.00526..0.00529 rows=1 loops=11)
      -> Filter: (m2_0.deleted_at is null)  (cost=0.25 rows=0.1) (actual time=0.00231..0.00238 rows=1 loops=11)
          -> Single-row index lookup on m2_0 using PRIMARY (id=m1_0.momenter_id)  (cost=0.25 rows=1) (actual time=0.00217..0.00219 rows=1 loops=11)

1. 인덱스를 사용해서 12개(페이징)의 Comment만 먼저 조회

-> Index lookup on c1_0 using idx_comments_commenter_created_id (commenter_id=1) (cost=154302 rows=192576) (actual time=0.708..0.712 rows=12 loops=1)

 

2. 조회한 12개의 Comment 를 Moment와 join (단일 primary key 사용)

-> Single-row index lookup on m1_0 using PRIMARY (id=c1_0.moment_id) (cost=0.706 rows=1) (actual time=0.00526..0.00529 rows=1 loops=11)

 

3. User 와 join (단일 primary key 사용)

-> Single-row index lookup on m2_0 using PRIMARY (id=m1_0.momenter_id) (cost=0.25 rows=1) (actual time=0.00217..0.00219 rows=1 loops=11)

옵티마이저가 인덱스를 선택하지 않는 경우

-> Limit: 11 row(s)  (actual time=54650..54650 rows=11 loops=1)
  -> Sort: c1_0.created_at DESC, c1_0.id DESC, limit input to 11 row(s) per chunk  (actual time=54650..54650 rows=11 loops=1)
      -> Stream results  (cost=169747 rows=604) (actual time=315..54535 rows=82940 loops=1)
          -> Nested loop inner join  (cost=169747 rows=604) (actual time=315..54282 rows=82940 loops=1)
              -> Nested loop inner join  (cost=55105 rows=12079) (actual time=0.382..6584 rows=921526 loops=1)
                  -> Filter: (m2_0.deleted_at is null)  (cost=10.6 rows=10.3) (actual time=0.0419..0.459 rows=103 loops=1)
                      -> Table scan on m2_0  (cost=10.6 rows=103) (actual time=0.0399..0.37 rows=103 loops=1)
                  -> Filter: (m1_0.deleted_at is null)  (cost=4188 rows=1173) (actual time=0.625..63.2 rows=8947 loops=103)
                      -> Index lookup on m1_0 using fk_moments_users (momenter_id=m2_0.id)  (cost=4188 rows=11727) (actual time=0.625..62 rows=9418 loops=103)
              -> Filter: ((c1_0.commenter_id = 1) and (c1_0.deleted_at is null))  (cost=8.48 rows=0.05) (actual time=0.0498..0.0516 rows=0.09 loops=921526)
                  -> Index lookup on c1_0 using fk_comments_moments (moment_id=m1_0.id)  (cost=8.48 rows=10.1) (actual time=0.0265..0.0506 rows=9.5 loops=921526)

옵티마이저가 인덱스를 선택하지 않는 경우에는 
1. User 테이블을 Full Table scan 103명의 user를 모두 조회

2. 103 명의 유저가 작성한 Moment를 모두 조인하여 무려 921,526개의 행을 생성 (엄청난 비효율)

3. 921,526의 행을 가지고 Comment 테이블을 마지막에 join 

 

그런데 옵티마이저는 인덱스를 사용하지 않는 경우의 cost를 
인덱스를 사용하는 경우 보다 더 낫다고 판단한다.

-> Filter: ((c1_0.commenter_id = 1) and (c1_0.deleted_at is null))  (cost=8.48 rows=0.05)

이 실행 계획을 보면 옵티마이저는 Comment join 단계에서 단 0.05 개의 행을 반환할 것이라는 예측을 하고 있다. 
이 지점이 옵티마이저가 결정적인 착각을 하고 있는 부분이다. 

쿼리 분리를 통한 조인 순서 지정

옵티마이저가 왜 이런 잘못된 코스트 계산을 하는 지 알아보는 것보다

인위적으로 join 순서를 지정해주는 것이 더 좋은 방법이라고 판단했다.

쿼리 분리를 통해 from절에서 join순서를 지정하도록 설정했다.

// 첫번째 쿼리: took 1ms
select c1_0.id 
from comments c1_0 
where (c1_0.deleted_at IS NULL) 
	and c1_0.commenter_id=3 
order by c1_0.created_at desc,c1_0.id desc limit 11;

// 두번째 쿼리: took 1ms
select c1_0.id,c1_0.commenter_id,c1_0.content,c1_0.created_at,c1_0.deleted_at,c1_0.moment_id,m1_0.id,m1_0.content,m1_0.created_at,m1_0.deleted_at,m1_0.is_matched,m1_0.momenter_id,m2_0.id,m2_0.available_star,m2_0.created_at,m2_0.deleted_at,m2_0.email,m2_0.exp_star,m2_0.level,m2_0.nickname,m2_0.password,m2_0.provider_type,m1_0.write_type 
from comments c1_0 
join moments m1_0 on m1_0.id=c1_0.moment_id 
	and (m1_0.deleted_at IS NULL) 
join users m2_0 on m2_0.id=m1_0.momenter_id 
	and (m2_0.deleted_at IS NULL) 
where (c1_0.deleted_at IS NULL) 
	and c1_0.id in (9215202,2328811,8760475,3034729,7713331,1111652,323437,4036837,516964,8747932,9195133) 
order by c1_0.created_at desc,c1_0.id desc;

인덱스를 사용하는 경우 에서 처럼 

메인이 되는 Comment 값의 id만 인덱스를 사용해 빠르게 찾아온다.

이후 조인은 11개의 데이터만으로 진행되므로 매우 빠르게 실행된다.

 

추가적으로 옵티마이저에게 실행계획을 맡기지 않고 개발자가 직접 실행 순서를 컨트롤 할 수 있게 된다.

결과

최종적으로 복합 인덱스 도입과 쿼리 분리 전략을 통해 성능 문제가 해결되었다.

특히, 복합 인덱스가 옵티마이저에게 정확한 실행 경로를 제공하면서 쿼리 성능이 극적으로 개선되었다.

-> Limit: 11 row(s)  (cost=170490 rows=11) (actual time=0.735..0.808 rows=11 loops=1)
 -> Nested loop inner join  (cost=170490 rows=193) (actual time=0.734..0.806 rows=11 loops=1)
     -> Nested loop inner join  (cost=169816 rows=1926) (actual time=0.725..0.777 rows=11 loops=1)
// (중략: Comment 테이블 접근)
         -> Index lookup on c1_0 using idx_comments_commenter_created_id (commenter_id=1)  (cost=154302 rows=192576) (actual time=0.708..0.712 rows=12 loops=1)
// (중략: Moment 테이블 조인)
         -> Single-row index lookup on m1_0 using PRIMARY (id=c1_0.moment_id)  (cost=0.706 rows=1) (actual time=0.00526..0.00529 rows=1 loops=11)
// (중략: User 테이블 조인)
     -> Single-row index lookup on m2_0 using PRIMARY (id=m1_0.momenter_id) (cost=0.25 rows=1) (actual time=0.00217..0.00219 rows=1 loops=11)

 

54초(54,650ms) 걸리던 쿼리가 단 0.8ms, 즉 1밀리초(ms)도 채 걸리지 않게 되었다.