포스트

[DB] 쿼리 분리를 통한 조회 성능 99.9% 향상시키기

0. 쿼리를 개선해야 하는 이유

기능을 개발했다고 끝난 것은 아니다. 당장은 유저가 없고, 데이터가 적어서 조회 속도가 빠르겠지만, 데이터가 100만, 1000만이 되면 우리의 DB가 멀쩡할까?

우리가 평소에 사용하는 서비스들을 생각해보자. 로딩이 0.n초라도 느리면, 우리는 바로 새로고침을 누르거나 페이지를 나가버린다. 이만큼 속도 문제는 치명적이다.

우리는 프로젝트에서 하나의 기능 실행 시에 54초 라는 믿을 수 없는 숫자를 0.2ms로 줄여냈다. 그 방법을 공유한다.

1. 데이터 준비하기

최대한 실제 운영환경과 가까운 데이터를 준비한다. 단순히 편의를 위해 테스트할 테이블의 데이터만 준비해두면 실제 운영환경과 달라져 문제를 식별하지 못할 수도 있다.

우리는 Datafaker라는 라이브러리를 사용해 데이터를 준비했다. Naver에서 만든 Fixture Monkey라는 라이브러리도 존재했지만, Fixture Monkey는 객체를 직접 만든다는 부분에서 우리가 사용하기에 부적절해 보였다. 최대 1000만건의 데이터를 만들어야 하는데, 이 모든 객체가 메모리에 올라갈 수 없다고 판단했다.

Datafaker는 단순 int 나 String값을 만들기에 csv로 작성하면 크게 메모리 낭비가 없었다. 또한 csv를 사용하면 DB 종속적인 코드를 만들지 않아도 되기 때문에 이 방법을 사용했다.

Datafaker

2. 쿼리 식별하기 & 소요시간 측정하기

우리는 ORM을 사용하기 때문에 실제로 어떤 쿼리가 생성되는지 알아야했다. 또 모든 쿼리를 직접 검증하기보다, 비정상적으로 느린 쿼리를 식별한 후 개선하는 것이 효율적이라 판단했다.

우리는 p6spy라는 라이브러리를 사용해, 실제 쿼리와 소요시간을 한 번에 볼 수 있도록 했다.

p6spy

Hibernate의 show_sql을 사용하지 않은 이유

물론, Hibernate의 기본 옵션을 사용하면 쿼리 로그를 볼 수 있다.

1
jpa.properties.hibernate.show_sql: true

하지만 이 옵션을 사용해 쿼리를 보면 실제 변수 부분이 “?” 로 처리되어, 디버깅이 어려웠다. p6spy를 사용하면 실제로 어떤 쿼리를 날렸는지 확인 가능하고, 추가적으로 쿼리 실행에 걸린 시간까지 로깅이 되어 편리했다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
took 10ms // <- 실제 쿼리가 소요된 시간
select c1_0.id,
       c1_0.commenter_id,
       c1_0.content,
       c1_0.created_at
       //(후략)
from comments c1_0
left join moments m1_0 on m1_0.id=c1_0.moment_id
    and m1_0.deleted_at IS NULL
left 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.commenter_id=1
order by c1_0.created_at desc, c1_0.id desc limit 11;

단, 실제 운영 환경에서는 성능 저하가 있을 수 있다. 반드시 테스트 / 개발 환경에서 사용하자.

3. 쿼리 작동 파악하기

문제가 되는 쿼리를 식별했으면 다음은 개선이다.

현직 DBA 분에게 들은 바에 의하면, 인덱스만 제대로 걸어줘도 대부분의 문제가 해결된다고 했다. 따라서 쿼리가 인덱스를 제대로 타는지 알아보아야 한다.

우리는 MySQL의 명령어 Explain, Explain Analyze 두 가지를 사용해 쿼리를 분석했다.

3.1 Explain

쿼리를 실행하기 전, 옵티마이저가 쿼리를 어떤 방식으로 실행할지 계획한 실행 계획을 보여준다. 실행한다면 대략 아래와 같은 결과를 보여준다.

idselect_typetablepartitionstypepossible_keyskeykey_lenrefrowsfilteredExtra
1SIMPLEm1_0nullrangefk_moments_users,moments_created_at_idmoments_created_at_id4null325Using index condition; Using where

가장 먼저 확인해야 하는 필드는 type 이다. 아래 테이블에 type 필드가 어떤 값을 가질 수 있고, 무슨 뜻을 가졌는지 정리한다.

순위타입설명성능 평가
1system / constPK나 Unique Key로 단 1건만 조회할 때.최상
2eq_ref조인 시 PK나 Unique Key를 사용하여 1건씩 매칭될 때.매우 좋음
3refNon-Unique 인덱스나, 인덱스의 일부(Prefix)만 사용하여 매칭될 때.좋음 (일반적 목표)
4range범위 검색(BETWEEN, >, <, IN)에 인덱스가 사용될 때.양호
5index인덱스 풀 스캔. 인덱스 트리를 처음부터 끝까지 다 읽음.느림 (주의)
6ALL풀 테이블 스캔. 디스크에 있는 모든 데이터를 다 읽음.최악 (즉시 튜닝 필요)

높은 확률로 초기엔 ALL을 만날 것이다. 테이블에 존재하는 인덱스를 사용하지 못한다는 뜻으로, 반드시 range 이상으로 개선해야 한다.

3.2 Explain Analyze

해당 명령어는 실제로 쿼리를 실행한다! 또한 실행 계획과 실제로 어떤 방식으로 실행됐는지 함께 보여준다. 아래는 실행 결과 예시이다.

1
2
3
4
5
6
7
8
9
-> 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. 들여쓰기가 가장 깊은 곳부터 시작한다.
  2. 같은 레벨이라면 위에서부터 읽는다.

예시 로그의 실행 순서를 분석해보면

  1. c1_0 테이블에서 idx_comments_commenter_created_id 인덱스를 활용해 commenter_id=1 인 데이터를 찾는다. 0.7ms가 걸렸고, 1번의 루프로 11개의 행을 반환했다.
1
2
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)
  1. 1번에서 나온 11개의 행에 대해 m1_0.id 를 사용해 단일 행을 찾아낸다.
1
2
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)
  1. 2번의 결과의 각각에 대해 m2_0.id 를 사용해 데이터를 조회한다.
1
2
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. 상위에서 요청한 대로 11개의 행을 반환한다. 최종 걸린 시간은 0.808ms, 비용은 cost=170490가 나왔다.

여기서 한 부분을 주목해보자. 현재 Optimizer는 예측치를 잘못 계산하고 있다.

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)

Optimizer는 해당 쿼리의 예상으로 19만건의 행이 반환될 것이라 예측했지만, 실제로는 12건의 행만 조회됐다.

이는 Optimizer가 갖고 있는 DB의 통계 정보가 오래됐거나, 데이터가 편향됐거나(예를 들어 특정 id의 값만 굉장히 많은 경우), 복잡한 필터 조건을 갖고 있을 때, 잘못된 예측을 한다.

4. 프로젝트 쿼리 개선

프로젝트에서 개선한 쿼리 개선 사례를 소개한다.

4.1 문제 상황

문제는 특정 사용자가 작성한 코멘트(댓글의 일종)을 조회하는 쿼리를 실행 시 발생했다. 해당 쿼리는 50초 이상 소요됐다.

애플리케이션에서 사용한 코드는 다음과 같다.

1
2
3
4
5
6
7
    @EntityGraph(attributePaths = {"moment.momenter"})
    @Query("""
            SELECT c FROM comments c
            WHERE c.commenter = :commenter
            ORDER BY c.createdAt DESC, c.id DESC
            """)
    List<Comment> findCommentsFirstPage(@Param("commenter") User commenter, Pageable pageable);

실제로 생성된 쿼리와 실행 계획은 다음과 같다.

쿼리

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
SELECT
    c1_0.id, c1_0.commenter_id, c1_0.content, c1_0.created_at, c1_0.moment_id,
    m1_0.content, m1_0.created_at, m1_0.momenter_id, m1_0.write_type,
    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
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.commenter_id = 1 
  AND c1_0.deleted_at IS NULL
ORDER BY 
    c1_0.created_at DESC, 
    c1_0.id DESC 
LIMIT 11;

실행계획

1
2
3
4
5
6
7
8
9
10
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. m2_0 테이블(users)에서 103개의 행을 찾아낸다. 0.37ms로 상당히 빠르다.
  2. m1_0 테이블(moments)에서 각각의 모멘트를 찾는다. 여기서 921,526개의 행이 생성된다. 이 단계까지 6.5초가 소요됐다.
  3. c1_0 테이블(comments) 에서 이 92만건을 각각 조인한다. 조회 후 commenter_id = 1 조건을 필터링한다. 이 단계에서 약 47초가 소요됐다.

즉 문제는, 비효율적인 드라이빙 순서에 있었다.

103명을 먼저 조회하고, 그 사람들이 작성한 모멘트(92만건)을 조회하고, 그 모멘트에 달린 모든 코멘트를 조회하려니 너무 비효율적이었다. 따라서 우리는 조인의 순서를 바꿔야 했다.

  1. commenter_id = 1인 코멘트를 먼저 찾는다. 최근 11건만 찾아내므로, 인덱스로 정렬되어 있다면 바로 11건을 찾을 수 있다. → 11건
  2. 이후 해당 코멘트에 대한 모멘트를 조인한다.
  3. 유저를 조인한다.

1번 과정만 복합 인덱스를 통해 빠르게 실행된다면 문제를 해결할 수 있을 것 같았다.

4.2 해결 방안1: 복합 인덱스

조인 순서를 바꾸기 위해 가장 처음 시도한 방식은 복합 인덱스 였다.

복합 인덱스는 테이블의 여러 열을 인덱스로 묶는 것이다. 쿼리 사용 시, 옵티마이저는 해당 인덱스를 사용할수밖에 없도록 유도하는 것이다.

해당 쿼리에선 comments 테이블의 commenter_id, deleted_at, created_at DESC, id DESC, moment_id 에 복합 인덱스를 설정했다.

1
2
CREATE INDEX idx_comments_covering 
ON comments (commenter_id, deleted_at, created_at DESC, id DESC, moment_id);

하지만, 안타깝게도 옵티마이저는 우리가 설정한 복합 인덱스를 선택해주지 않았다. 더 황당한 점은, Force Index를 통해 강제로 인덱스를 선택하게 하면 조회 속도가 굉장히 빨랐다는 것이다.

Force Index를 통한 실행계획, 우리가 의도한 조인 방향대로 실행됐다.

1
2
3
4
5
6
7
8
9
-> 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)

하지만 Force Index는 사용하지 않았다. 이유는 native query의 불편함이다.

  1. 컴파일 타임에서의 에러를 찾을 수 없다. 인덱스 이름이 변경되거나 하는 변경사항에 너무 취약해진다.
  2. 매핑하기 위한 DTO(매핑 객체)가 필요하다.
  3. DB 종속 쿼리에 묶여버린다. 유연한 DB 변경(이런 일이 있을까는 차치하고)에 대응할 수 없다.

결국 ORM이 제공하는 객체지향적 이점을 포기하는 방향이라 생각돼 선택하지 않았다.

4.3 해결방안2: Application 레벨 조인

우리는 Application에서 조인 순서를 직접 정해주기로 했다.

우리는 위에 설계한 Join 순서를 각각 쿼리로 만든 후 Application에서 직접 합쳐줬다.

  1. 특정 유저의 최신 코멘트 11개의 id를 찾는다.
  2. 이후 11개의 id로 모멘트와 유저를 조인해 가져온다.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
@Query("""
           SELECT c.id
           FROM comments c
           WHERE c.commenter = :commenter
           ORDER BY c.createdAt DESC, c.id DESC
           """)
    List<Long> findFirstPageCommentIdsByCommenter(@Param("commenter") User commenter, Pageable pageable);

@Query("""
           SELECT c
           FROM comments c
           LEFT JOIN FETCH c.moment m
           LEFT JOIN FETCH m.momenter
           WHERE c.id IN :ids
           ORDER BY c.createdAt DESC, c.id DESC
		       """)
    List<Comment> findCommentsWithDetailsByIds(@Param("ids") List<Long> ids);

첫 번째 쿼리는 우리가 설계한 인덱스를 그대로 활용할 수 있다. 쿼리에 필요한 모든 열을 인덱스에 포함한 것을 커버링 인덱스 라고 하는데, 이 방식을 사용해 굉장히 빠르게 조회가 가능해졌다.

또한 하나의 거대한 기능을 두 개의 작은 기능으로 분리했다. 따라서 재활용성이 올라갔다고 볼 수 있다. 어떤 ID가 필요한가?어떻게 보여줄 것인가를 관심사를 분리해냈다.

5. 느낀 점

우리 팀은 이 과정에서 몇 가지 인사이트를 얻었다.

무분별한 Join은 독이다

물론, 조인을 아예 배제할거면 RDB를 쓰는 이유가 없다. 하지만 우리의 경우처럼 서로 약한 관계가 있는 객체들을 한번에 조인으로 엮어버리면 문제가 생길 수 있다고 느꼈다.

우리는 해당 경험으로 우리 프로젝트의 구조를 DDD와 유사한 형식으로 변경했다. 계층은 늘어났지만 객체들 간의 과도한 의존이 사라졌다.

개발자의 통제 영역을 늘리자

우리는 이번 개선에서 두 가지 블랙박스를 만났다. JPAOptimizer 이다.

JPA는 우리가 간단한 코드만 작성하며 쿼리를 직접 만들어준다. 심지어 컴파일 시점에 에러도 잡을 수 있다. 너무나 편리하다. 하지만 어떤 쿼리가 실제로 DB에 날아갈지는 알지 못한다.

Optimizer는 스스로 실행 계획을 판단한다. 비용을 계산해 조인 순서도 결정한다. 편리하지만, 개발자가 개입할 수 있는 부분이 없다.

개발자가 프레임워크나 시스템의 모든 부분에 관여할 수는 없다. 그래서는 너무 비효율적이고, 도구를 사용하는 의미가 없어진다. 하지만 우리의 경우처럼 너무 휘둘리는 것은 문제가 있다.



이 기사는 저작권자의 CC BY 4.0 라이센스를 따릅니다.