Post

몽고DB 슬로우 쿼리 분석하기

영향력

고객사에서 특정 기능 조회가 너무 느리다고 연락이 왔다. 바로 스케일업 얘기가 나왔는데, 그것보다는 더 나은 방안이 분명히 있을 것 같았다. 좋은 경험이 될 것 같아서 내가 주말에 조사해보고 월요일날 공유하기로 했다.

요즘 일하다가 종종, 내가 하는 업무가 비즈니스적으로 얼마나 영향력이 있을까 고민해본다. 어차피 우리가 개발하는 이유도 다 회사 사업에 기여해서 돈 벌려고 하는거 아니겠나. 가끔 혼자서 발악하는 기분이 든다. ‘쟤는 그냥 일이 좋나 보네’ 라는 말로 내가 고민했던 시간들이 너무나도 쉽게 다뤄지는 것 같다.
그럴땐 그냥 내가 운이 좋은 놈이라 생각한다. 적성에 맞는 직업을 가진다는 건 축복이다. 그래도 같은 관심사를 공유하는 사람들과 함께하고 싶다는 소망은 늘 있다. 결국 이 문단의 끝도 비겁하게, 사실 다 알면서 ‘모르겠다’ 라는 말로 회피하려나 보다. 내 다음 스텝은 뭘 해야 좋을까. 모르겠다.

혼자 주저리주저리 해봤다. 각설하고 쿼리 얘기나 해보자.

현황 파악

채팅 목록이랑 세부 채팅을 조회할 때 퍼포먼스가 느려진다고 해서 데이터가 어느정도인지, 스펙은 어느정도인지 살펴봤다. 정리해보면 다음과 같다.

  • API 호출: 3 ~ 6s
  • DB 스펙: 4 vCore, 16GB 램, 256GB 저장소
  • 채팅 목록: 100만건
  • 세부 채팅 내역: 300만건

인덱스는 id랑 생성 시각, 업데이트 시각에만 걸려있는데 이 조건들로 쿼리를 안해서… 사실상 없다. 쿼리중 일부는 문자 검색을 위해 정규표현식을 이용한다. 쉽게 말하면 MySQL의 Like %’텍스트’% 라고 보면 된다. 어디를 고쳐야 좋을까 생각해보다가, 검색 조건 같은건 그쪽의 요구사항이었을 가능성이 높다보니, 갑자기 필터 조건이 바뀐다면 문제가 생길수도 있을 것 같아서 인덱스를 효율적으로 걸어보기로 했다

한 가지 다행인건 쿼리의 순서가 중요한 RDB에 비해, 몽고의 aggregation Pipeline에는 여러 매칭 조건이 있다면 인덱스를 효율적으로 활용한다는 것이다. 예를 들어보자면,

1
2
3
4
5
6
7
8
9
db.collection.aggregate([
  {
    $match: {
      content: { $regex: "검색어", $options: "i" } // ❌ 인덱스 없음
      userId: ObjectId("xxx"),                    // ✅ 인덱스 존재
      // 기타 등등 다른 조건....
    }
  }
])

이런 식으로 여러개의 매칭 조건이 섞여있다면 인덱스를 활용해 범위를 좁히고 작업을 진행한다.

  1. IXSCAN (userId 인덱스 사용)
  2. FETCH (userId로 걸러진 도큐먼트 조회)
  3. FILTER (content regex 적용)

요렇게 말이다.

개발 환경 세팅

개발을 위해 우리쪽 환경도 유사하게 부하를 줘봤다. 사양은 낮아지고 데이터는 더 많아졌기 때문에 더 오버드라이브 했다는 표현이 맞을 것 같다. 기존의 1 : 3 비율이던 채팅 목록과 채팅내역 도 1 : 4로 조절해봤다. 구성한 환경은 다음과 같다.

  • API 호출: 3 ~ 6s
  • DB 스펙: 2 vCore, 8GB 램, 32GB 저장소
  • 채팅 목록: 100만건
  • 세부 채팅 내역: 400만건

api 호출 시간도 비슷하게 맞춰졌고, 실행 계획을 이리저리 살펴보며 인덱스를 걸어봤다.

실행 계획 분석

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
db.컬렉션.aggregate([
        {
            "$match": {
                조건들
            }
        },
        {"$addFields": {필드 추가}},
        {"$sort": {정렬}},
        {"$skip": 0},
        {"$limit": 30},
    ]).explain()


[
  {
    "$cursor": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "COLLSCAN",
          "runtimeFilterSet": [
             // .....
          ],
          "estimatedTotalKeysExamined": new NumberInt("1968")
        }
      }
    }
  },
  {
    "$sort": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "SORT",
          "sortKeysCount": new NumberInt("1"),
          "estimatedTotalKeysExamined": new NumberInt("1968")
        }
      }
    }
  },
  {
    "$limit": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "LIMIT",
          "estimatedTotalKeysExamined": new NumberInt("30"),
          "inputStage": {
            "stage": "ADDFIELDS",
            "estimatedTotalKeysExamined": new NumberInt("30"),
            "inputStage": {
              "stage": "COLLSCAN",
              "estimatedTotalKeysExamined": new NumberInt("3936")
            }
          }
        }
      }
    }
  }
]

기존 쿼리다. COLLSCAN이 Collection Scan의 줄임말이라고 하는데, 결국 풀스캔 같다. 마땅한 인덱스가 없으니 다 훑어보는 것 같다. 복합인덱스도 고려해봤는데 카디널리티가 높은 값이 사실상 한개뿐이고 나머지는 true false 느낌이라 중복도가 낮은 값에만 걸어보기로 했다.

참고로 estimatedTotalKeysExamined는 후보군으로 뽑힌 문서의 갯수고, IXSCAN 은 인덱스 스캔이라고 한다. FETCH는 추가적으로 불러오는 행위같은데, IXSCAN 다음에 나오면 인덱스를 못 탄거고, 그 전에 나오면 인덱스를 이용해 좁힌 문서에서 추가 로딩을 진행한 것이라고 한다.

일단 인덱스를 건 결과를 보자

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
db.컬렉션.createIndex({
    컬럼럼: 1
})


db.컬렉션.aggregate([
        {
            "$match": {
                // .....
            }
        },
        {"$sort": {// .....}},
        {"$skip": 0},
        {"$limit": 30},
    ]).explain()



[
  {
    "$cursor": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "FETCH",
          "runtimeFilterSet": [
            // .....
          ],
          "estimatedTotalKeysExamined": new NumberInt("4723"),
          "inputStage": {
            "stage": "IXSCAN",
           // .....
            "estimatedTotalKeysExamined": new NumberInt("10202")
          }
        }
      }
    }
  },
  {
    "$sort": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "SORT",
          "sortKeysCount": new NumberInt("1"),
          "estimatedTotalKeysExamined": new NumberInt("4723")
        }
      }
    }
  },
  {
    "$limit": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "LIMIT",
          "estimatedTotalKeysExamined": new NumberInt("30")
        }
      }
    }
  }
]

특정 컬럼에 인덱스를 걸었다. Fetch 안에 인덱스 스캔이 포함된걸 보니 뭔가 타긴 한 것 같다. api 호출 결과를 비교해보면 200~300ms 내외로 줄었다. 부지런히 다음 인덱스를 걸러 가보자.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
[
  {
    "$cursor": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "COLLSCAN",
          "runtimeFilterSet": [
            // .....
          ],
          "estimatedTotalKeysExamined": new NumberInt("212448")
        }
      }
    }
  },
  {
    "$sort": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "SORT",
          "sortKeysCount": new NumberInt("1"),
          "estimatedTotalKeysExamined": new NumberInt("212448")
        }
      }
    }
  },
  {
    "$root": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "COLLSCAN",
          "estimatedTotalKeysExamined": new NumberInt("424896")
        }
      }
    }
  }
]

여기도 여지없이 풀스캔 중이다. 특이했던게 채팅 내역이라 채팅방 아이디만 있으면 조회가 가능할 것 같은데 유저 이름이랑 같이 쿼리중이었다. 이건 내용 공유하고 수정해야겠다. 필요 없을 것 같다. 어쨌든 결과를 보자.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
db.컬렉션.createIndex({
    컬럼: 1
})


db.컬렉션.aggregate([
        {
            "$match": {
                // .....
            }
        },
        {"$sort": {// .....}},
    ]
).explain()

[
  {
    "$cursor": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "FETCH",
          "runtimeFilterSet": [
            // .....
          ],
          "estimatedTotalKeysExamined": new NumberInt("424635"),
          "inputStage": {
            "stage": "IXSCAN",
            // .....
        }
      }
    }
  },
  {
    "$sort": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "SORT",
          "sortKeysCount": new NumberInt("1"),
          "estimatedTotalKeysExamined": new NumberInt("424635")
        }
      }
    }
  },
  {
    "$root": {
      "queryPlanner": {
        "winningPlan": {
          "stage": "COLLSCAN",
          "estimatedTotalKeysExamined": new NumberInt("849270")
        }
      }
    }
  }
]

인덱스를 걸었는데 마지막에 COLLSCAN이 나오고 있었다. gpt말로는 정렬 쿼리 때문이란다. 아마 유저의 채팅 내역을 가져와서 시간순대로 정렬하는 것 같은데, 앱단에서 정렬한다는 가정하에 sort를 빼봤다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
db.컬렉.aggregate([
        {
            "$match": {
                // .....
            }
        },
    ]
).explain()


[
  {
    "$cursor": {
      "queryPlanner": {
        "namespace": "",
        "winningPlan": {
          "stage": "FETCH",
          "runtimeFilterSet": [
            {
              // .....
            }
          ],
          "estimatedTotalKeysExamined": new NumberInt("1019124"),
          "inputStage": {
            "stage": "IXSCAN",
             // .....
            "estimatedTotalKeysExamined": new NumberInt("40765")
          }
        }
      }
    }
  }
]

뭔가 깔끔하게 실행 계획이 나왔다. gpt말로는 db 메모리상에서 정렬을 수행중이라 부담될 수 있다고 한다.

앱단에서 정렬할까 생각도 했는데, 종종 하나의 채팅방만 계속 사용하는 유저들이 있다고 들었다. 아마 대화 맥락을 계속 기억시키고 싶어서 그런 것 같은데, 앱단에서 정렬하기 vs DB에서 정렬하기 과연 어떤 게 부담이 덜한 방식일지는 고민을 조금 더 해봐야겠다.

api 호출 결과는 역시 200~300ms 내외로 줄었다.

결론

3 ~ 6초 걸리던 api들을 200~300ms 내외로 줄였다. 이제 내용 공유하고 운영 환경에서 인덱스 생성을 해야할 것 같은데, 운영 환경에서는 인덱스 생성을 해본 경험이 없어서 어떤 걸 주의해야 하는지, 역효과는 뭐가 있을지 계속 찾아보고 있다.

오늘따라 잡생각이 많은 것 같다. 이만 줄여야겠다.

This post is licensed under CC BY 4.0 by the author.

© . Some rights reserved.

Using the Jekyll theme Chirpy