Recursive Query 도입기 그 후: 10초나 걸렸던 이유가 뭘까?

3년 전에 계층 구조의 데이터를 다루는 Recursive Query 도입기라는 글을 작성했었다. 이 글에서는 데이터 간의 계층이 생기는 카테고리 기능의 DB 조회 쿼리를 개선하기 위해 Recursive CTE를 사용했던 경험에 대한 설명했다.

다시 이 글을 읽어보니 이런 생각이 들었다.

아무리 생각해도 수치의 급격한 변화가 크게 와닿지 않았다. 분명 당시엔 API 호출 실험을 했었고 그에 대한 결과를 명확하게 작성한 것도 맞는데 말이다.

수치만 가지고는 이를 설명할 수 없다는 생각에 다시 실험을 해보았다. 이 글은 가설을 세워 실험을 설계하고 실험하고 그 결과를 보고한다.

해당 실험은 Claude Code와 함께 설계하고 실험하고 원인을 찾는 과정을 포함한다. 실험에 사용한 스펙은 다음과 같다.

• PostgreSQL 16.4 (Docker)
• Python 3.12, Flask 3.0, Flask-SQLAlchemy 3.1.1, SQLAlchemy 2.0.36, psycopg 3.2, toxiproxy 2.9.0

3년 전의 쿼리 최적화에 대해서

인수인계 받은 카테고리 조회 기능에 대한 작업이었다. 카테고리 수가 많아질수록 API 응답이 많이 느려졌던 이유가 시작점이었다.

가장 의심했던 것은 쿼리 부분이었다. 다른 기능들도 같이 문제였다면 인프라나 네트워크를 의심을 했을텐데 그렇지 않았다. 따라서 가장 눈여겨 본 부분은 ‘DB 조회를 할 때 ORM 쿼리가 어떻게 써져 있었는가’였다.

AS-IS는 노드마다 자식을 조회하는 재귀 함수 get_descendants였다. 노드가 100개면 루트 조회를 포함하여 쿼리가 총 101번 나간다. 전형적인 N+1 구조다. TO-BE는 WITH RECURSIVE로 트리 전체를 한 번에 가져오는 get_recursive_cte다.

TO-BE로 ORM 코드를 개선한 이후에 API 전체 응답 시간은 약 10초에서 약 200ms가 됐다. 자세한 코드 내용은 이전 글에도 있으며, 하단에 작성하였다.

카테고리 조회 쿼리 다시 보기

카테고리 모델

python
class Category(db.Model):
    __tablename__ = "categories"

    id = db.Column(db.Integer, primary_key=True, autoincrement=True, nullable=False)
    parent_id = db.Column(db.Integer, foreign_key=[id])  # 계층 구조를 만들기 위해 사용했던 parent_id, Category 모델 자신을 참조할 수 있다.
    name = db.Column(db.String)

    parent = db.relationship(
        "Category",
        primaryjoin="Category.parent_id == Category.id",
        foreign_keys=[parent_id],
        remote_side=[id],
    )

AS-IS: 노드마다 자식을 조회하는 재귀 로직(A 쿼리)

python
class Category(db.Model):
		# ... attribute 선언부 생략

    def get_descendants(self):
        """category 인스턴스의 모든 자식(자손)을 가져와서 dictionary 형태로 보내주는 메서드"""
        # 카테고리 인스턴스의 자식을 모두 가져올 땐 Category.parent == self로 가져온다.
        children = Category.query.filter(Category.parent == self).all()
        
        children_list = []
        for child in children:
		        # child도 후손을 가져오게 하기 위해 재귀적으로 호출한다.
		        # 이 부분이 N+1 쿼리가 나는 곳
            ele = child.get_descendants()
            children_list.append(ele)
        
        # 참고: 리턴 값은 딕셔너리로 변환해서 보냈다.
        return {
            "id": self.id,
            "name": self.name,
            "children": children_list,
        }

TO-BE: recursive cte를 이용한 DB 조회 로직(B 쿼리)

python
class Category(db.Model):
		# ... attribute 선언부 생략

    @classmethod
    def get_recursive_cte(cls):
        """get_result_recursive의 CTE 구성부"""
        
        # 시작 쿼리 작성부
        start_query = db.session.query(
            cls.id,
            postgresql.array([cls.parent_id]).label("c_path"),
            cls.name,
            literal(1).label("depth"),
        ).filter(
            cls.parent_id.is_(None)
        ).cte("category_cte", recursive=True)

				# 재귀 쿼리 작성부
        repeat_query = db.session.query(
            cls.id,
            start_query.c.c_path + postgresql.array([cls.parent_id]),
            cls.name,
            start_query.c.depth + 1,
        ).filter(
            cls.parent_id == start_query.c.id
        )

        return start_query.union_all(repeat_query)

    @classmethod
    def get_result_recursive(cls, term):
        """재귀 쿼리 ORM을 이용해 데이터를 가져올 수 있습니다."""
        recursive_query = cls.get_recursive_cte()
        query = db.session.query(recursive_query)

				# 참고: 이전 글에는 term filter가 있었으나
				# 전체 트리 가져오는 쿼리 비교를 위해 filter를 삭제했다.
        return query.all()

sql
WITH RECURSIVE category_cte AS (
	SELECT  -- 시작 쿼리: 일반적으로 시작 쿼리는 parent_id가 null
		id,
		ARRAY[parent_id] AS "c_path",
		"name",
		1 AS "depth"
	FROM categories
	WHERE parent_id IS NULL
	UNION ALL
	SELECT  -- 재귀로 돌릴 쿼리를 작성하여 UNION ALL
		c.id,
		category_cte."c_path" || c.parent_id ,  -- path를 계속 찾아 줌
		c."name",
		category_cte."depth" + 1  -- 현재 데이터의 depth를 찾아 줌
	FROM categories c, category_cte
	WHERE c.parent_id = category_cte.id
)
SELECT * FROM category_cte

python
def assemble(rows):
    nodes = {row.id: {"id": row.id, "name": row.name, "children": []} for row in rows}
    root = None
    for row in sorted(rows, key=lambda row: row.id):
        parent_id = row.c_path[-1]
        if parent_id is None:
            root = nodes[row.id]
        else:
            nodes[parent_id]["children"].append(nodes[row.id])
    return root

첫 번째 실험: 재현 실험 설계하기

목표 세우기

쿼리 최적화 당시의 AS-IS와 TO-BE 코드는 그대로 두고, 카테고리 100개 이상일 때 실제로 10000ms(10초)에서 200ms로 줄어드는지 확인한다.

데이터 준비하기

각 배치별로 100 / 1000 / 10000개의 레코드(계층 구조에서는 ‘노드’ 단위)를 생성한 후, 트리를 구성하였다. 최대 depth는 노드 수에 따라 4 ~ 6로, 최대 자식 수 10개로 설정하였다.

측정 방법

• 정확성: A와 B의 결과가 같은지(assert a == b) 확인한 뒤에만 측정한다.
• 쿼리 수: SQLAlchemy before_cursor_execute 이벤트로 센다.
• 응답 시간: 워밍업 1회 후 5회 실행한 값의 중앙값을 쓴다. A와 B는 라운드마다 번갈아 실행했다.

실험 결과

두 쿼리의 성능 차이는 노드가 100개일 때도 약 30배 차이가 났고, 노드가 1000개 이상이면 약 85배까지 벌어졌다.

이는 두 쿼리를 처리하는 DB비용과 앱 ↔ DB 간 왕복 비용, 그리고 ORM 처리 비용과 관련 있다. 쿼리 플랜 결과를 함께 보면 좀 더 이해가 쉽다.

EXPLAIN ANALYZE

해당 쿼리 플랜은 노드 1만 개일 때 기준으로 측정되었다.

• A(노드마다 자식을 조회하는 재귀 로직)
  • 자식 조회 1회마다 테이블 1만 행을 모두 읽는다(Seq Scan, 약 1 ms)
  • 앱에서 잰 시간은 쿼리당 약 1.6 ms(15699 ms / 10001)이고, 그중 약 1 ms가 Sequential Scan 비용, 그 외 비용은 왕복과 ORM 처리 비용이다.
  • 이 비용이 노드 수만큼, 즉 10001번 반복되어 전체 약 15.7초가 된다.
• B(recursive cte를 이용한 DB 조회 로직)
  • Seq Scan이 트리 깊이(6)만큼만 일어나서 DB 실행은 21 ms
  • 나머지(전체 186 ms)는 1만 행을 받아 추가 로직을 수행하는 시간이다. 즉, ORM이 행으로 변환하고, Python에서 트리로 조립하는 시간

끝인 줄 알았지만, 새로운 가설을 세웠다

이번 실험에서 10000ms(10초) → 200ms처럼 확연하게 차이가 났던 건, 카테고리 개수가 100개가 아닌 10000개였을 때였다. 오히려 이 실험에서 카테고리 100개일 때의 두 쿼리 차이는 73.7ms → 2.5ms이므로, 개선이 되었다는 체감을 할 수 없는 수준의 차이었다. 하지만 쿼리 최적화 당시의 카테고리 개수는 100여 개 뿐이었다.

당시 작성한 기록이 맞으면, 이번 실험에 빠진 조건이 있을 수 있겠다는 생각을 했다. 그래서 조건을 추가하여 새로운 테스트를 했다.

N+1쿼리를 고려한 조건 추가하기

이 때 생각한 것은 ‘N+1 쿼리여서 생기는 문제가 무엇인가’였다. 쿼리 1회의 비용이 생각한 것보다 더 클 때 크게 차이가 날 것이라는 예상이었다.

• 가정 1: 쿼리 수행 횟수는 그대로(102회, BEGIN 수행 횟수 포함)이고, 1회 비용이 예상보다 컸다
  • AS-IS의 당시 수치를 수행 횟수로 나눠 보면, 10000ms(10초) / 102회 = (쿼리 수행 1회 당) 약 100 ms다.
  • TO-BE도, 200ms / 2회 = (쿼리 수행 1회 당) 약 100ms 의 비용으로 설명된다.
• 가정2: 쿼리 수행 비용이 1ms로 고정되어 있고, 횟수가 예상보다 많았다.
  • 반대로 ‘쿼리 1회 비용이 아주 작고(예를 들어 1ms) 쿼리가 102번보다 훨씬 많았다’고 가정하면 AS-IS의 10초는 설명할 수 있다.
  • 하지만 쿼리가 2번 뿐인 TO-BE는, 이 가정에서 1ms * 2회 = 2ms를 기대하지만 실제로는 200ms가 나오니 설명에 부합하지 않는다.

따라서 쿼리 1회 비용이 100ms 정도로 비쌌을 것이란 가설을 세울 수 있다.

그렇다면 앱에서 실행한 ORM 쿼리 1회에 100 ms가 걸리는 이유는 무엇일까? 노드 100개짜리 테이블이라면 Sequential Scan을 해도 DB 실행은 1 ms도 걸리지 않는다. 그래서 DB 실행보다는 앱과 DB 사이의 ‘DB 왕복 지연’이 크게 기여했을 거라 예상했다.

앞선 실험은 동일한 docker network 안에서 Flask-SQLAlchemy 실행 애플리케이션과 PostgreSQL 컨테이너를 함께 띄우고 실험을 했다. 앱 ↔ DB 간 왕복이 1ms도 되지 않는다. 보통의 서비스 환경은 앱과 DB 서버가 따로 있기 마련이므로 이보단 왕복 시간이 길다. 3년 전, 당시 환경이 어땠는지 이젠 알 수 없지만, 현재 필자의 테스트 환경과 차이가 나는 부분이다.

두 번째 실험: DB 왕복 지연을 추가하여 실험해보기

DB 왕복 지연은 toxiproxy 라는 테스트 툴을 이용했다. 네트워크 장애 주입 프록시로, 앱과 DB 사이에 두면 DB 응답이 돌아올 때마다 지연을 넣을 수 있다. 쿼리 실행 자체는 그대로 두고, 왕복 시간만 늘어난다.

렌더링 중...

렌더링 중...

이번 실험에서는 카테고리 개수를 아예 100개로 고정했다. 대신 추가 지연을 0 / 1 / 5 / 20 / 50 / 100 ms로 순차적으로 늘려 가며 두 쿼리의 실행 시간을 측정했다.

결과

DB 지연이 추가되니 카테고리 100개인 경우에도 두 쿼리의 차이가 10528ms → 206ms로 차이가 났다. 3년 전 기록(약 10초 → 약 200ms)과 거의 동일하다. 따라서 N+1 쿼리의 비용에는 DB 조회 비용 뿐만이 아닌, 앱과 DB 사이 간 왕복 비용 또한 이 차이에 크게 기여한다는 점을 알았다.

API 호출 비용(실험과 달리 HTTP 비용 포함되었을 때의 비용)을 측정했던 3년 전과는 완벽하게 동일한 환경에서 실험한 것이 아니다. 당시 왕복이 왜 100 ms 수준이었는지도 확인할 수 없다. 그렇기에 이 실험으로 말할 수 있는 건 "그런 환경이었다면 쿼리만 바꿨을 때 같은 숫자가 나온다"까지다. 다만 이번 실험을 통해 N+1 쿼리가 API 호출에 크게 영향을 주는 이유를 더 단계적으로 확인하는 계기가 되었다.

References

• https://github.com/liza0525/n-plus-one-vs-recursive-cte-benchmark
  • 이번 실험을 하기 위해 작성한 코드와 결과 보고서 repository
• https://www.lizziechung.com/posts/postgresql-recursive-query
  • 계층 구조의 데이터를 다루는 Recursive Query 도입기