PostgreSQL에서 EXPLAIN ANALYZE 읽기

1. 개요

EXPLAIN ANALYZE는 PostgreSQL에서 느린 쿼리를 진단하는 가장 중요한 도구입니다. 이 글은 output의 각 부분을 읽는 법을 알려줍니다: node type, cost, rows, actual time, 그리고 쿼리에 문제가 있는지 판단하는 방법. 이 글을 읽으면 execution plan을 자신감 있게 읽을 수 있고, 어디에 index를 추가해야 할지, 어디서 쿼리를 수정해야 할지 알 수 있습니다.

2. EXPLAIN vs EXPLAIN ANALYZE

EXPLAIN은 통계를 기반으로 예상 계획(estimated plan)만 표시하며, 실제로 쿼리를 실행하지 않습니다. EXPLAIN ANALYZE는 실제로 쿼리를 실행하고 실제 시간을 측정합니다.

-- 예상 계획만 보고, 쿼리를 실행하지 않음
EXPLAIN SELECT * FROM orders WHERE customer_id = 42;

-- 실제로 실행하고 실제 시간을 측정
EXPLAIN ANALYZE SELECT * FROM orders WHERE customer_id = 42;

주의: EXPLAIN ANALYZE는 실제로 쿼리를 실행하므로, UPDATE 또는 DELETE인 경우 데이터가 변경됩니다. 테스트하려면 transaction 내에서 실행하고 ROLLBACK을 사용하세요:

BEGIN;
EXPLAIN ANALYZE UPDATE orders SET status = 'SHIPPED' WHERE id = 1;
ROLLBACK;

3. Plan의 각 node 구조

output의 각 줄은 하나의 node — 데이터를 처리하는 한 단계입니다. orders 테이블 예시:

EXPLAIN ANALYZE
SELECT * FROM orders WHERE customer_id = 42;

Seq Scan on orders  (cost=0.00..1834.00 rows=10 width=72)
                     (actual time=0.015..12.430 rows=8 loops=1)
  Filter: (customer_id = 42)
  Rows Removed by Filter: 99992
Planning Time: 0.120 ms
Execution Time: 12.465 ms

각 부분 설명:

Seq Scan on orders: node의 종류, 여기서는 전체 테이블을 순차적으로 스캔합니다.
cost=0.00..1834.00: 예상 비용 (startup cost .. total cost), 상대 단위, ms가 아닙니다.
rows=10: planner가 반환할 것으로 예상하는 행의 수입니다.
width=72: 각 행의 평균 크기(바이트)입니다.
actual time=0.015..12.430: 실제 시간(ms) — 첫 행 반환 시작 .. node 완료까지.
rows=8 loops=1: 실제로 반환된 행의 수, 그리고 이 node가 실행된 횟수(loops).
Rows Removed by Filter: 스캔했지만 filter와 일치하지 않는 행의 수 — 이 숫자가 크면 index가 부족한 신호입니다.

4. Seq Scan과 Index Scan 비교

4.1. Index가 없을 때

EXPLAIN ANALYZE
SELECT * FROM orders WHERE customer_id = 42;

Seq Scan on orders  (cost=0.00..1834.00 rows=10 width=72)
                     (actual time=0.015..12.430 rows=8 loops=1)
  Filter: (customer_id = 42)
Execution Time: 12.465 ms

PostgreSQL은 전체 테이블을 읽은 후 각 행을 필터링해야 합니다. 큰 테이블의 경우 이것이 느린 주된 원인입니다.

4.2. Index 추가 후

CREATE INDEX idx_orders_customer_id ON orders (customer_id);

EXPLAIN ANALYZE
SELECT * FROM orders WHERE customer_id = 42;

Index Scan using idx_orders_customer_id on orders
  (cost=0.29..8.31 rows=10 width=72)
  (actual time=0.018..0.025 rows=8 loops=1)
  Index Cond: (customer_id = 42)
Execution Time: 0.045 ms

비교: cost는 1834에서 8.31로 감소, execution time은 12.465 ms에서 0.045 ms로 감소했습니다. 이것은 index가 PostgreSQL이 필요한 행으로 바로 이동할 수 있게 해주고, 전체 테이블 스캔이 필요 없다는 것을 보여주는 전형적인 예입니다.

주의: PostgreSQL은 index가 있더라도 항상 사용하지 않습니다. 쿼리가 테이블의 대부분을 반환하는 경우(예: 행의 20-30% 이상), planner는 보통 Seq Scan을 선택합니다. 왜냐하면 index를 통해 무작위로 점프한 후 테이블로 돌아가는 것(random I/O)보다 비용이 낮기 때문입니다.

5. JOIN이 있는 plan 읽기

쿼리에 join이 있으면 plan은 여러 중첩 node를 가집니다. 자식 node가 먼저 실행되고, 결과는 부모 node로 전달됩니다.

EXPLAIN ANALYZE
SELECT o.id, c.name
FROM orders o
JOIN customers c ON o.customer_id = c.id
WHERE c.country = 'VN';

Hash Join  (cost=45.50..520.75 rows=200 width=40)
           (actual time=1.200..8.900 rows=195 loops=1)
  Hash Cond: (o.customer_id = c.id)
  ->  Seq Scan on orders o
        (cost=0.00..420.00 rows=10000 width=12)
        (actual time=0.010..3.500 rows=10000 loops=1)
  ->  Hash  (cost=40.00..40.00 rows=440 width=36)
            (actual time=1.100..1.100 rows=440 loops=1)
        ->  Seq Scan on customers c
              (cost=0.00..40.00 rows=440 width=36)
              (actual time=0.005..0.700 rows=440 loops=1)
              Filter: (country = 'VN'::text)
Execution Time: 9.050 ms

읽는 방법: Hash Join은 가장 바깥쪽 node(root)이고, 두 개의 자식 node(Seq Scan on orders와 Hash 안의 Seq Scan on customers)에서 데이터를 받습니다. PostgreSQL은 필터된 customers 테이블에서 hash table을 만든 후, orders를 스캔하고 hash table과 일치시킵니다. 부모 node의 actual time은 내부의 자식 node들의 시간을 포함합니다.

6. 주의할 경고 신호

6.1. 예상과 실제의 큰 차이

Seq Scan on orders  (cost=0.00..1834.00 rows=10 width=72)
                     (actual time=0.015..12.430 rows=9500 loops=1)

Planner는 rows=10을 예상했지만 실제로는 9500을 반환했습니다. 이 정도의 큰 차이는 보통 오래된 통계로 인한 것입니다. 해결 방법:

ANALYZE orders;

이 명령은 데이터 분포 통계를 업데이트하여 planner가 더 정확하게 예상할 수 있도록 합니다.

6.2. 비정상적으로 큰 Loops (Nested Loop)

Nested Loop  (cost=0.43..5000.00 rows=1 width=40)
             (actual time=0.020..450.000 rows=1 loops=1)
  ->  Seq Scan on customers c (actual time=0.010..0.015 rows=1 loops=1)
  ->  Index Scan on orders o
        (actual time=0.002..0.450 rows=1 loops=1000)

loops=1000은 node Index Scan on orders이 1000번 호출되었다는 의미입니다(외부 node의 1000개 행에 해당). 각 호출이 시간이 걸린다면 이 node의 actual time이 작아 보이더라도 총 비용은 매우 클 수 있습니다. actual time에 loops를 곱해서 node의 실제 총 시간을 추정하세요.

6.3. I/O 확인을 위해 `BUFFERS` 사용

EXPLAIN (ANALYZE, BUFFERS)
SELECT * FROM orders WHERE customer_id = 42;

Index Scan using idx_orders_customer_id on orders
  (cost=0.29..8.31 rows=10 width=72)
  (actual time=0.018..0.025 rows=8 loops=1)
  Index Cond: (customer_id = 42)
  Buffers: shared hit=4
Execution Time: 0.045 ms

shared hit=4는 4개의 block이 cache(메모리)에서 읽혀졌고 disk에 접근하지 않았다는 의미입니다. shared read가 크면 데이터를 disk에서 읽어야 한다는 뜻입니다 — cache miss의 신호이며, shared_buffers가 너무 작거나 쿼리가 많은 콜드 데이터를 스캔하기 때문일 수 있습니다.

7. Java/Spring 코드에서 EXPLAIN 사용

Spring Boot 애플리케이션에서 성능을 디버깅할 때, JdbcTemplate을 통해 plan을 직접 로깅할 수 있습니다:

@Service
public class QueryDiagnosticsService {

    private final JdbcTemplate jdbcTemplate;

    public QueryDiagnosticsService(JdbcTemplate jdbcTemplate) {
        this.jdbcTemplate = jdbcTemplate;
    }

    public List<String> explainAnalyze(String sql) {
        String query = "EXPLAIN (ANALYZE, FORMAT TEXT) " + sql;
        return jdbcTemplate.queryForList(query, String.class);
    }
}

explainAnalyze는 원본 SQL을 받아 EXPLAIN (ANALYZE, FORMAT TEXT)로 래핑하고 각 plan 줄을 String으로 반환합니다. dev/staging 환경에서 느린 쿼리를 감지할 때 plan을 로깅하는 데 사용하세요.

@Test
void explainAnalyze_shouldReturnPlanWithExecutionTime() {
    QueryDiagnosticsService service = new QueryDiagnosticsService(jdbcTemplate);

    List<String> plan = service.explainAnalyze(
        "SELECT * FROM orders WHERE customer_id = 42"
    );

    assertThat(plan)
        .isNotEmpty()
        .anyMatch(line -> line.contains("Execution Time"));
}

이 테스트는 구체적인 숫자를 assert하지 않습니다(시간은 머신마다 변하므로). 대신 반환된 plan이 Execution Time 줄을 포함하는지만 확인합니다 — 쿼리가 성공적으로 실행되고 유효한 plan을 반환했다는 것을 확인하기에 충분합니다.

주의: INSERT/UPDATE/DELETE 쿼리에 대해 production에서 transaction + ROLLBACK 없이 EXPLAIN ANALYZE를 실행하면 안 됩니다. 실제로 실행되기 때문입니다.

8. EXPLAIN ANALYZE가 필요 없을 때

쿼리가 이미 빠르고 안정적입니다(몇 ms 이하, 적은 데이터) — 더 이상 최적화할 필요 없고, 노력이 보람이 없습니다.
초기 schema 설계 단계에서 통계가 실제 데이터를 반영할 수 있을 정도의 데이터가 없습니다(행이 적으면 Seq Scan이 항상 Index Scan을 이깁니다).
쿼리가 한 번만 작은 임시 테이블(TEMP TABLE)에서 실행되는 경우 — 분석 오버헤드는 이득에 비해 보람이 없습니다.

9. 결론

EXPLAIN ANALYZE는 PostgreSQL이 생각하는 일(cost, 예상 행)과 실제로 일어나는 일(actual time, 실제 행) 사이의 차이를 보여줍니다. plan을 읽을 때는 실행 순서(안에서 바깥으로), node의 종류(Seq Scan 또는 Index Scan), 그리고 특히 예상과 실제 사이의 차이에 주의하세요 — 이것이 쿼리에 index가 필요한지, 테이블을 다시 ANALYZE해야 하는지, 아니면 로직을 다시 작성해야 하는지 알 수 있는 열쇠입니다.