Skip to content
Published on

EXPLAIN ANALYZE 읽는 법 — 실행 계획에서 진짜 병목을 찾는 순서

공유하기
Authors

들어가며 — 실행 계획은 봤는데 어디가 느린지 모르겠다면

느린 쿼리를 만나면 대부분 EXPLAIN ANALYZE를 붙여 봅니다. 그리고 화면을 가득 채운 들여쓰기와 괄호 속 숫자를 한참 보다가, 결국 "Seq Scan이 보이니 인덱스를 만들자"는 결론으로 건너뜁니다. 그 결론이 맞을 때도 있습니다. 하지만 실행 계획이 알려 주려던 것은 대개 다른 이야기입니다.

실행 계획을 읽는다는 것은 노드 이름을 훑는 일이 아닙니다. 옵티마이저의 예측과 실제 결과 사이의 괴리를 찾는 일입니다. 괴리가 없다면 옵티마이저는 자기가 아는 정보 안에서 최선을 골랐다는 뜻이고, 남은 병목은 물리적인 문제입니다. 괴리가 크다면 옵티마이저는 틀린 전제 위에서 정확하게 계산한 것이고, 손봐야 할 대상은 쿼리가 아니라 통계입니다.

이 글은 실제 출력을 한 줄씩 해부하면서, 어떤 숫자를 어떤 순서로 보아야 하는지를 정리합니다. PostgreSQL을 기준으로 하고, MySQL이 달라지는 지점은 그때그때 짚겠습니다.

EXPLAIN과 EXPLAIN ANALYZE — 하나는 예측, 하나는 실행

두 명령은 이름만 비슷할 뿐 하는 일이 다릅니다.

-- 계획만 세우고 끝. 쿼리는 실행되지 않는다.
EXPLAIN
SELECT * FROM orders WHERE user_id = 42;

-- 실제로 실행한 뒤, 계획에 실측치를 얹어서 보여준다.
EXPLAIN (ANALYZE, BUFFERS)
SELECT * FROM orders WHERE user_id = 42;

EXPLAIN만 붙이면 옵티마이저가 통계를 근거로 세운 계획과 추정치만 나옵니다. 빠르고 안전하지만, 그 추정이 맞는지는 알 수 없습니다. ANALYZE 옵션을 붙이면 쿼리를 실제로 실행하고 각 노드가 실제로 몇 행을 내놓았는지, 얼마나 걸렸는지를 함께 출력합니다.

여기서 자주 사고가 납니다. EXPLAIN ANALYZE UPDATE ...는 진짜로 UPDATE를 수행합니다. 쓰기 쿼리를 분석할 때는 반드시 트랜잭션으로 감싸고 롤백해야 합니다.

BEGIN;
EXPLAIN (ANALYZE, BUFFERS)
UPDATE orders SET status = 'shipped' WHERE id = 1001;
ROLLBACK;

옵션은 몇 가지 더 있고, 실무에서 유용한 조합은 사실상 정해져 있습니다.

EXPLAIN (ANALYZE, BUFFERS, VERBOSE, SETTINGS, FORMAT TEXT)
SELECT ...;
  • BUFFERS — 노드별 블록 읽기 통계. 이게 없으면 캐시 문제를 볼 수 없습니다.
  • VERBOSE — 출력 컬럼 목록과 스키마 한정 이름. 조인이 복잡할 때 유용합니다.
  • SETTINGS — 기본값에서 벗어난 플래너 파라미터를 표시합니다. 남이 만든 환경을 조사할 때 결정적입니다.
  • FORMAT JSON — 도구에 넣어 파싱할 때만 쓰고, 사람이 읽을 때는 TEXT가 낫습니다.

MySQL에서는 8.0.18부터 EXPLAIN ANALYZE가 생겼고, 그 이전에는 EXPLAIN FORMAT=TREESHOW WARNINGS로 옵티마이저가 다시 쓴 쿼리를 확인하는 방식이었습니다. 출력 형태는 다르지만 읽는 원칙은 같습니다.

출력을 읽는 순서 — 안쪽 노드부터, 아래에서 위로

실행 계획은 트리입니다. 텍스트로 출력될 때 들여쓰기가 깊을수록 트리의 안쪽, 즉 먼저 실행되는 노드입니다. 위에서 아래로 읽으면 반대로 읽는 셈입니다.

EXPLAIN (ANALYZE, BUFFERS)
SELECT u.name, o.id, o.total
FROM users u
JOIN orders o ON o.user_id = u.id
WHERE u.country = 'KR'
  AND o.created_at >= '2026-06-01';
Hash Join  (cost=1842.00..24310.55 rows=18420 width=44)
           (actual time=8.412..131.207 rows=17903 loops=1)
  Hash Cond: (o.user_id = u.id)
  Buffers: shared hit=4021 read=9877
  ->  Seq Scan on orders o  (cost=0.00..20117.00 rows=92300 width=20)
                            (actual time=0.019..92.441 rows=91188 loops=1)
        Filter: (created_at >= '2026-06-01 00:00:00'::timestamp)
        Rows Removed by Filter: 708812
        Buffers: shared hit=3110 read=9004
  ->  Hash  (cost=1610.00..1610.00 rows=18560 width=28)
            (actual time=8.287..8.288 rows=18402 loops=1)
        Buckets: 32768  Batches: 1  Memory Usage: 1408kB
        Buffers: shared hit=911 read=873
        ->  Seq Scan on users u  (cost=0.00..1610.00 rows=18560 width=28)
                                 (actual time=0.011..5.902 rows=18402 loops=1)
              Filter: (country = 'KR'::text)
              Rows Removed by Filter: 61598
              Buffers: shared hit=911 read=873
Planning Time: 0.184 ms
Execution Time: 133.902 ms

읽는 순서는 이렇습니다.

  1. 가장 깊이 들여쓰인 Seq Scan on users u가 먼저 실행되어 18402행을 만듭니다.
  2. 그 결과가 Hash 노드로 올라가 메모리에 해시 테이블로 적재됩니다.
  3. 그다음 Seq Scan on orders o가 91188행을 흘려보냅니다.
  4. 최상단 Hash Join이 둘을 결합해 17903행을 냅니다.

즉 형제 노드가 여럿일 때는 위쪽이 먼저이고, 부모 노드는 자식이 끝난 뒤에 완성됩니다. 트리 구조에 익숙해지면 계획을 보자마자 "데이터가 어디서 만들어져 어디로 흐르는가"가 눈에 들어옵니다.

한 가지 주의할 점이 있습니다. 부모 노드의 actual time은 자식의 시간을 포함한 누적값입니다. 위 출력에서 Hash Join의 131ms 중 92ms는 orders 스캔이 쓴 시간입니다. 특정 노드가 순수하게 쓴 시간을 알려면 자식의 시간을 빼야 합니다. 이 사실을 모르면 "조인이 131ms나 걸린다"는 잘못된 결론에 도달합니다.

cost는 시간이 아니고, rows의 괴리가 진짜 신호다

cost=1842.00..24310.55에서 앞의 값은 첫 행을 내놓기까지의 비용, 뒤의 값은 마지막 행까지의 총비용입니다. 문제는 이 숫자의 단위입니다. 밀리초가 아닙니다. 초도 아닙니다. 순차 페이지 한 장을 읽는 비용을 1.0으로 놓은 임의 단위입니다.

-- 비용 단위의 기준값들
SHOW seq_page_cost;      -- 1.0  (기준)
SHOW random_page_cost;   -- 4.0  (기본값, SSD라면 1.1 근처가 현실적)
SHOW cpu_tuple_cost;     -- 0.01
SHOW cpu_operator_cost;  -- 0.0025

그래서 cost 24310이 24초를 뜻하지 않습니다. 이 값은 같은 쿼리의 여러 계획 후보를 서로 비교하기 위한 점수일 뿐이고, 다른 쿼리의 cost와 비교하는 것도 사실상 의미가 없습니다. "cost가 10000이 넘으면 위험하다" 같은 기준을 세우는 조언을 종종 보는데, 근거가 없습니다.

정말 봐야 할 것은 같은 노드 안의 rows= 두 개입니다.

->  Seq Scan on orders o  (cost=... rows=92300 ...) (actual ... rows=91188 loops=1)

예상 92300, 실제 91188. 오차 1.2퍼센트면 통계가 건강하다는 뜻입니다. 반대로 이런 출력을 만나면 이야기가 달라집니다.

->  Index Scan using idx_orders_status on orders o
      (cost=0.42..8.44 rows=1 width=20)
      (actual time=0.031..214.882 rows=482913 loops=1)

예상 1행, 실제 482913행. 4만 배 이상 틀렸습니다. 옵티마이저는 "1행만 나올 테니 Nested Loop로 붙이면 되겠다"고 판단했을 것이고, 그 전제가 무너지면서 안쪽 노드를 48만 번 반복하게 됩니다. 이때 고쳐야 할 것은 조인 힌트가 아니라 통계입니다.

-- 1차 처방: 통계 갱신
ANALYZE orders;

-- 그래도 어긋나면 특정 컬럼의 히스토그램 정밀도를 올린다
ALTER TABLE orders ALTER COLUMN status SET STATISTICS 1000;
ANALYZE orders;

-- 컬럼 간 상관관계 때문에 틀리는 경우 (예: 도시와 우편번호)
CREATE STATISTICS stat_orders_geo (dependencies, ndistinct)
  ON city, postal_code FROM orders;
ANALYZE orders;

마지막 확장 통계는 의외로 자주 필요합니다. 옵티마이저는 기본적으로 조건들이 서로 독립이라고 가정하고 선택도를 곱합니다. 실제로는 상관관계가 있는 컬럼 쌍이 많고, 그럴 때 추정치는 실제보다 훨씬 작게 나옵니다.

loops가 곱해진다 — actual time은 1회 평균이다

가장 많은 오독이 여기서 나옵니다.

->  Index Scan using idx_order_items_order_id on order_items i
      (cost=0.43..3.21 rows=4 width=16)
      (actual time=0.008..0.011 rows=4 loops=52310)

actual time=0.008..0.011을 보고 "0.011밀리초면 무시해도 되겠다"고 넘어가면 안 됩니다. 괄호 안의 시간과 행 수는 모두 1회 실행 기준 평균값입니다. 실제 총합은 loops를 곱해야 나옵니다.

  • 총 소요 시간: 0.011ms 곱하기 52310회 = 약 575ms
  • 총 반환 행: 4행 곱하기 52310회 = 약 209,240행

전체 쿼리가 700ms라면 이 노드 하나가 80퍼센트를 쓴 셈입니다. 계획 어디에도 "575"라는 숫자는 적혀 있지 않기 때문에, 곱셈을 직접 해 보지 않으면 병목을 지나칩니다.

같은 이유로 Nested Loop 안쪽 노드는 항상 loops를 먼저 확인해야 합니다. loops가 수만 회를 넘어간다면 바깥쪽의 행 수 추정이 틀렸을 가능성이 큽니다. 조인 순서를 바꿀지, 인덱스를 추가할지는 그다음 문제입니다.

병렬 쿼리에서는 한 겹이 더 있습니다. Gather 아래 노드의 loops는 워커 수를 반영하고, Workers Launched가 요청한 수보다 적을 수 있습니다.

Gather  (cost=1000.00..38210.13 rows=210 width=8)
        (actual time=0.412..312.884 rows=198 loops=1)
  Workers Planned: 4
  Workers Launched: 2

4개를 계획했지만 2개만 떴다면 max_parallel_workers가 이미 소진된 상태라는 뜻이고, 그만큼 예상보다 느려집니다. 벤치마크 결과가 재현되지 않는다면 이 줄을 먼저 보십시오.

Seq Scan은 죄가 없다, 그리고 조인 세 가지가 갈리는 지점

"Seq Scan이 보이면 인덱스를 만들어라"는 조언은 절반만 맞습니다. 순차 스캔이 인덱스 스캔보다 빠른 상황이 분명히 존재합니다.

첫째, 테이블이 작을 때입니다. 몇백 행짜리 코드 테이블은 통째로 읽어도 페이지 몇 장입니다. 인덱스를 타면 인덱스 페이지를 읽고 힙으로 다시 랜덤 접근해야 하므로 오히려 손해입니다.

둘째, 선택도가 낮을 때입니다. 조건이 테이블의 상당 비율을 통과시킨다면 인덱스는 불리합니다. 인덱스 스캔은 매칭되는 행마다 힙 페이지를 랜덤하게 방문하는데, 방문할 행이 많으면 결국 테이블 전체를 랜덤 순서로 읽는 꼴이 됩니다. 순차 읽기는 디스크와 프리페치에 훨씬 친화적입니다. 대략 전체의 5에서 10퍼센트를 넘어가면 순차 스캔이 이기기 시작하고, 정확한 경계는 random_page_cost와 물리적 정렬도가 결정합니다.

-- 물리적 정렬도 확인: 1.0에 가까울수록 인덱스 순서와 힙 순서가 일치한다
SELECT attname, correlation
FROM pg_stats
WHERE tablename = 'orders' AND attname IN ('id', 'created_at', 'user_id');
  attname    | correlation
-------------+-------------
 id          |    0.999812
 created_at  |    0.998304
 user_id     |    0.003911

user_id의 상관도가 0에 가깝다는 것은 같은 사용자의 주문이 테이블 전체에 흩어져 있다는 뜻입니다. 이런 컬럼은 같은 선택도라도 인덱스 이득이 훨씬 작습니다. 옵티마이저는 이 값을 이미 알고 계산에 넣습니다.

조인 알고리즘도 마찬가지로 "무엇이 좋다"가 아니라 "언제 무엇이 맞다"의 문제입니다.

조인 방식선택되는 조건비용 특성계획에서 의심할 신호
Nested Loop바깥쪽 행 수가 적고 안쪽에 조인 키 인덱스가 있을 때바깥쪽 행 수 곱하기 안쪽 조회 비용loops가 수만 회 이상이고 안쪽이 Seq Scan
Hash Join등호 조인이고 작은 쪽을 메모리 해시 테이블로 올릴 때작은 쪽 전체를 메모리에 적재Batches가 1보다 크고 Disk 사용량이 표시됨
Merge Join양쪽이 조인 키로 정렬되어 있거나 정렬이 싸게 끝날 때정렬 비용 더하기 각 입력 1회 스캔앞단 Sort가 external merge로 떨어짐

Hash Join에서 Batches: 1이 아니면 해시 테이블이 work_mem에 다 들어가지 못해 디스크로 쪼개졌다는 뜻입니다.

->  Hash  (actual time=412.331..412.332 rows=1840221 loops=1)
      Buckets: 65536  Batches: 32  Memory Usage: 4097kB

Batches 32는 32번에 나눠 처리했다는 의미이고, 그 사이 임시 파일 입출력이 발생합니다. 이 경우 인덱스를 만드는 것보다 해당 세션의 work_mem을 올리는 편이 훨씬 효과적입니다.

SET LOCAL work_mem = '256MB';

전역 설정을 올리는 것은 위험합니다. work_mem은 커넥션당이 아니라 쿼리 안의 정렬이나 해시 연산 하나당 할당되기 때문에, 동시 실행 쿼리가 많으면 메모리가 순식간에 몇 배로 불어납니다. 무거운 배치 쿼리 앞에서 세션 단위로만 올리는 것이 안전합니다.

BUFFERS와 Rows Removed by Filter — 나머지 두 단서

BUFFERS가 없는 EXPLAIN ANALYZE는 반쪽입니다. 같은 쿼리가 어제는 20ms, 오늘은 900ms인 이유는 대개 계획이 아니라 캐시에 있습니다.

->  Bitmap Heap Scan on events e  (actual time=44.201..811.339 rows=214402 loops=1)
      Recheck Cond: (tenant_id = 77)
      Heap Blocks: exact=41883
      Buffers: shared hit=1204 read=40801

shared hit은 버퍼 캐시에서 바로 찾은 블록, shared read는 캐시에 없어 운영체제나 디스크로 내려간 블록입니다. 위 출력은 4만 블록, 약 320MB를 캐시 밖에서 읽었다는 뜻입니다. 두 번째 실행에서 read가 급감하고 시간이 짧아진다면 계획은 문제가 없고 워킹셋이 shared_buffers보다 크다는 이야기입니다. 이때 인덱스를 더 만드는 것은 답이 아닙니다.

dirtiedwritten도 눈여겨볼 값입니다. SELECT인데 dirtied가 크다면 힌트 비트 갱신이나 사후 정리가 일어나고 있다는 신호로, 대량 적재 직후에 흔히 보입니다.

두 번째 단서는 Rows Removed by Filter입니다. 앞의 예제로 돌아가 보겠습니다.

->  Seq Scan on orders o  (actual time=0.019..92.441 rows=91188 loops=1)
      Filter: (created_at >= '2026-06-01 00:00:00'::timestamp)
      Rows Removed by Filter: 708812

80만 행을 읽어서 71만 행을 버렸습니다. 필요한 행은 전체의 11퍼센트뿐입니다. 이 정도 선택도라면 인덱스가 이길 여지가 충분합니다.

CREATE INDEX CONCURRENTLY idx_orders_created_at
  ON orders (created_at);

ANALYZE orders;
Hash Join  (cost=1842.00..9714.22 rows=18420 width=44)
           (actual time=7.902..28.113 rows=17903 loops=1)
  Hash Cond: (o.user_id = u.id)
  Buffers: shared hit=6188 read=1204
  ->  Index Scan using idx_orders_created_at on orders o
        (cost=0.43..5901.10 rows=92300 width=20)
        (actual time=0.028..14.882 rows=91188 loops=1)
        Index Cond: (created_at >= '2026-06-01 00:00:00'::timestamp)
  ...
Execution Time: 29.440 ms

133ms에서 29ms로 줄었고, Rows Removed by Filter 줄이 사라졌으며 Index Cond로 바뀌었습니다. 이 차이는 중요합니다. Filter는 행을 읽은 뒤에 버리는 것이고, Index Cond는 애초에 읽지 않는 것입니다. 계획에서 Filter 아래 큰 숫자를 발견했다면 그 조건을 인덱스로 올릴 수 있는지 먼저 검토하십시오.

반대로 이런 경우도 있습니다.

->  Index Scan using idx_orders_user_id on orders o
      (actual time=0.041..38.221 rows=112 loops=1)
      Index Cond: (user_id = 42)
      Filter: (status = 'pending')
      Rows Removed by Filter: 9884

인덱스로 1만 행을 좁혔지만 그중 112행만 남았습니다. 이 경우는 복합 인덱스나 부분 인덱스가 답입니다.

CREATE INDEX CONCURRENTLY idx_orders_user_pending
  ON orders (user_id)
  WHERE status = 'pending';

마치며 — 노드 이름이 아니라 괴리를 보라

실행 계획을 볼 때 순서를 하나만 기억하십시오.

  1. Execution TimePlanning Time을 먼저 봅니다. 계획 시간이 실행 시간을 넘는다면 문제는 다른 곳에 있습니다.
  2. 각 노드에서 예상 rows와 실제 rows를 비교합니다. 한 자릿수 배율 이상 벌어진 가장 안쪽 노드가 범인입니다.
  3. loops가 1이 아닌 노드는 곱셈을 해서 실제 기여 시간을 계산합니다.
  4. Rows Removed by Filter가 큰 노드를 찾아 인덱스 기회를 확인합니다.
  5. Buffers의 read 비율로 이것이 계획 문제인지 캐시 문제인지 가릅니다.

Seq Scan이나 Nested Loop 같은 노드 이름 자체는 좋고 나쁨을 말해 주지 않습니다. 옵티마이저는 자기가 가진 통계 안에서는 거의 항상 합리적으로 판단합니다. 그러니 계획이 이상해 보인다면 던져야 할 질문은 왜 옵티마이저가 멍청한가가 아니라, 내가 옵티마이저에게 무엇을 잘못 알려 주었는가입니다.