EXPLAIN ANALYZE로 PostgreSQL 쿼리 뜯어보기: 슬로우 쿼리 4가지 진단과 PgBadger 리포트 자동화 실전기

새벽 2시에 울린 알럿: 명절 정산 배치가 멈췄던 그 밤

설 연휴 직전이었습니다. 평소 새벽 1시에 시작해 1시간 안에 끝나던 정산 배치가 그날따라 2시가 넘어도 돌아가고 있었습니다. PagerDuty 알럿이 울렸고, 슬랙에는 SRE 온콜 담당자의 메시지가 쏟아졌습니다. 우리 팀은 급하게 접속해 APM 대시보드를 열었습니다. 원인은 단 하나의 SQL이었습니다. 평소라면 23초 안에 끝나던 정산 집계 쿼리가 그날 밤 트래픽 급증 이후 수십 분째 실행 중이었습니다. 명절 기간 주문 수가 평소의 78배로 불어난 것이 테이블 통계 정보를 완전히 뒤집어 놓았고, 플래너가 선택한 실행 계획은 더 이상 현실을 반영하지 못하고 있었습니다.

그 밤 이후 우리 팀은 PostgreSQL 쿼리 튜닝을 체계적으로 접근하기로 했습니다. 그냥 인덱스 하나 추가하고 넘어가는 게 아니라, EXPLAIN ANALYZE 출력을 제대로 읽고 플래너가 무슨 결정을 왜 내렸는지를 이해한 뒤 처방을 내리는 방식으로 바꿨습니다. 이 글은 그 과정에서 직접 마주쳤던 슬로우 쿼리 케이스 4가지와 PgBadger를 이용한 리포트 자동화까지, 운영 환경에서 실제로 써먹을 수 있는 내용만 담습니다. 인덱스 자료구조 배경지식이 부족하다면 데이터베이스 인덱싱 원리를 먼저 참고하면 이 글의 내용이 훨씬 빠르게 이해됩니다.

---

1. 슬로우 쿼리란 무엇인가: PostgreSQL이 "느리다"고 판단하는 기준

PostgreSQL 자체는 "이 쿼리가 느리다"는 판단을 사용자를 대신해 내려주지 않습니다. 슬로우 쿼리 판단 기준은 운영자가 직접 파라미터로 정의해야 합니다.

log_min_duration_statement

postgresql.conf에서 설정하는 임계값입니다. 이 시간(밀리초 기준)을 초과한 쿼리는 PostgreSQL 로그에 자동으로 기록됩니다.

-- postgresql.conf 또는 ALTER SYSTEM으로 설정
ALTER SYSTEM SET log_min_duration_statement = 1000;  -- 1초 이상 쿼리 로깅
SELECT pg_reload_conf();

0으로 설정하면 모든 쿼리를 기록하고, -1이면 비활성화됩니다. 운영 환경에서는 500ms~1000ms 사이로 잡는 것이 일반적입니다. 너무 낮게 잡으면 로그 볼륨이 폭발하고 디스크 I/O가 오히려 성능을 갉아먹습니다.

한국 서버 환경에서 추가로 챙겨야 할 설정이 하나 있습니다.

-- KST(한국 표준시) 기준으로 로그 타임스탬프를 찍어야
-- 새벽 배치 장애 분석 시 시간대 혼동을 막을 수 있습니다.
ALTER SYSTEM SET log_timezone = 'Asia/Seoul';
SELECT pg_reload_conf();

NHN Cloud나 Naver Cloud Platform의 관리형 PostgreSQL을 쓰는 경우에도 이 파라미터는 파라미터 그룹에서 조정 가능합니다. UTC로 찍힌 로그를 KST로 역산하다가 배치 시작 시각을 1시간 틀리게 읽는 실수는 의외로 잦습니다.

pg_stat_statements로 상위 슬로우 쿼리 추출

log_min_duration_statement가 개별 쿼리를 로그에 기록하는 방식이라면, pg_stat_statements 확장은 누적 통계를 DB 내부에 집계합니다. 특정 쿼리가 하루 동안 몇 번 실행됐고, 총 실행 시간이 얼마인지를 하나의 뷰에서 볼 수 있습니다.

-- 확장 설치 (슈퍼유저 권한 필요, 재기동 없이 가능)
CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

-- postgresql.conf에 추가 후 pg_reload_conf() 호출
-- shared_preload_libraries = 'pg_stat_statements'
-- pg_stat_statements.max = 10000
-- pg_stat_statements.track = all

-- 총 실행 시간 기준 상위 슬로우 쿼리 20개 추출
-- PostgreSQL 13부터 total_time → total_exec_time, mean_time → mean_exec_time으로 변경됨
-- PostgreSQL 12 이하에서는 total_time, mean_time을 사용해야 합니다.
SELECT
    round(total_exec_time::numeric, 2)  AS total_ms,
    round(mean_exec_time::numeric, 2)   AS mean_ms,
    calls,
    round((total_exec_time / sum(total_exec_time) OVER ()) * 100, 2) AS pct,
    left(query, 120)                    AS query_snippet
FROM pg_stat_statements
WHERE calls > 10
ORDER BY total_exec_time DESC
LIMIT 20;

mean_exec_time이 높은 쿼리는 개별 실행이 느린 것이고, total_exec_time이 높은 쿼리는 자주 호출되거나 오래 걸리는 것입니다. 우선순위는 보통 total_exec_time 기준으로 잡되, mean_exec_time이 수 초를 넘는 쿼리는 즉시 조사합니다. pct 컬럼으로 "이 쿼리 하나가 전체 DB 실행 시간의 몇 %를 차지하는가"를 파악하면 튜닝 우선순위 결정이 훨씬 빠릅니다.

---

2. EXPLAIN vs EXPLAIN ANALYZE: 플랜 읽기 전에 반드시 알아야 할 차이

세 가지 실행 모드 비교

옵션	쿼리 실제 실행	실제 rows·time	Buffer 정보	주 용도
EXPLAIN	아니오	없음(추정치만)	없음	플래너 예측 확인, 운영 DB 안전 실행
EXPLAIN ANALYZE	예	있음	없음	실제 실행 시간·행수 확인
EXPLAIN (ANALYZE, BUFFERS)	예	있음	있음	캐시 히트율·디스크 I/O 병목 진단
EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON)	예	있음	있음	프로그래밍 방식 파싱, pev2 등 시각화 도구

PostgreSQL 16 공식 문서(postgresql.org/docs/16/sql-explain.html)에 따르면, BUFFERS 옵션은 단독으로도 사용할 수 있지만 실제 I/O 수치를 얻으려면 ANALYZE와 반드시 함께 써야 합니다. ANALYZE 없이 BUFFERS만 쓰면 플래너 추정 기반 정보만 출력되어 실질적인 진단 가치가 없습니다.

출력 핵심 필드 해설

Seq Scan on orders  (cost=0.00..9240.00 rows=320000 width=48)
                    (actual time=0.021..187.432 rows=317842 loops=1)
  Filter: (status = 'COMPLETED')
  Rows Removed by Filter: 2158
  Buffers: shared hit=4120 read=924
Planning Time: 0.312 ms
Execution Time: 201.748 ms

• cost=0.00..9240.00: 플래너 추정 비용입니다. 첫 번째 숫자(0.00)는 첫 행을 반환하기까지의 스타트업 비용, 두 번째(9240.00)는 전체 행 반환까지의 총 비용입니다. 단위는 임의의 "비용 단위"로 절대값보다 노드 간 상대 비교가 중요합니다.
• actual time=0.021..187.432: 밀리초 단위 실제 실행 시간입니다. 0.021은 스타트업, 187.432는 마지막 행 반환까지의 총 시간입니다.
• rows=317842: 이 노드가 실제로 반환한 행 수입니다. 플래너 추정치(320000)와 비교해 크게 차이나면 통계 정보가 오래됐다는 신호입니다.
• loops=1: 이 노드가 반복 실행된 횟수입니다. Nested Loop 내부의 노드라면 이 값이 수천이 될 수 있습니다. actual time은 루프 1회당 평균이므로, 실제 총 시간은 actual time × loops로 계산합니다.
• Buffers: shared hit=4120 read=924: hit는 PostgreSQL 공유 버퍼 캐시에서 읽은 8KB 블록 수, read는 디스크(또는 OS 페이지 캐시)에서 읽은 블록 수입니다. read가 높으면 캐시 미스가 많다는 뜻으로 I/O 병목을 의심합니다.

운영 환경에서 EXPLAIN ANALYZE를 안전하게 사용하는 법

EXPLAIN ANALYZE는 쿼리를 실제로 실행합니다. SELECT는 괜찮지만, UPDATE나 DELETE를 EXPLAIN ANALYZE로 실행하면 데이터가 정말로 바뀝니다. 운영 DB에서 실수를 방지하는 트랜잭션 롤백 트릭은 필수로 알아둬야 합니다.

-- UPDATE/DELETE의 EXPLAIN ANALYZE를 안전하게 실행하는 방법
BEGIN;

EXPLAIN (ANALYZE, BUFFERS)
UPDATE orders
SET status = 'PROCESSED'
WHERE created_at < NOW() - INTERVAL '30 days'
  AND status = 'PENDING';

-- 실행 계획과 실제 수치를 확인한 후 반드시 롤백
ROLLBACK;

BEGIN 없이 바로 실행하면 트랜잭션이 자동 커밋됩니다. 이 패턴을 팀 전체의 관행으로 만들어두지 않으면, 어느 날 스테이징 DB가 아닌 프로덕션에서 의도치 않게 대량 업데이트가 발생합니다.

---

3. 실전 케이스 1: Seq Scan이 의심스러울 때 — 인덱스가 있는데 왜 안 쓰나

우리 환경에서 가장 자주 마주친 패턴입니다. orders 테이블의 customer_id 컬럼에 인덱스가 분명히 있는데, 플래너가 Seq Scan을 선택했습니다.

-- 문제 쿼리
SELECT order_id, total_amount, created_at
FROM orders
WHERE customer_id = 10042
  AND status = 'COMPLETED';

-- EXPLAIN (ANALYZE, BUFFERS) 출력 (명절 피크 직후 캡처)
Seq Scan on orders  (cost=0.00..47820.00 rows=3 width=32)
                    (actual time=0.033..1823.441 rows=4821 loops=1)
  Filter: ((customer_id = 10042) AND (status = 'COMPLETED'::text))
  Rows Removed by Filter: 8175342
  Buffers: shared hit=2180 read=19642
Planning Time: 0.228 ms
Execution Time: 1847.203 ms

플래너 추정 rows=3, 실제 rows=4821. 추정치가 실제의 1/1000 수준에 불과합니다. 명절 트래픽이 폭증한 뒤 통계 정보가 현실을 따라가지 못한 결과입니다.

selectivity와 pg_stats 관계

플래너가 인덱스를 무시하는 이유는 간단합니다. 통계 정보(pg_stats)를 보고 "이 쿼리가 테이블 전체 행의 상당 부분을 반환한다"고 판단하면, 인덱스를 경유하는 것보다 순차 스캔이 더 빠르다고 결론 냅니다. 인덱스 스캔은 랜덤 I/O를 유발하고 순차 스캔은 연속 I/O이기 때문에, 선택도(selectivity)가 낮을 때(즉, 필터가 대부분의 행을 통과시킬 때) Seq Scan이 실제로 더 효율적입니다.

통계가 틀리면 플래너도 틀린 결정을 내립니다. enable_seqscan = off로 인덱스 플랜을 강제해 둘을 직접 비교해볼 수 있습니다.

-- 개발·분석용 세션에서만 사용. 운영 환경 영구 설정 금지.
SET enable_seqscan = off;

EXPLAIN (ANALYZE, BUFFERS)
SELECT order_id, total_amount, created_at
FROM orders
WHERE customer_id = 10042
  AND status = 'COMPLETED';

Index Scan using idx_orders_customer_id on orders
  (cost=0.56..16.84 rows=3 width=32)
  (actual time=0.041..11.728 rows=4821 loops=1)
  Index Cond: (customer_id = 10042)
  Filter: (status = 'COMPLETED'::text)
  Rows Removed by Filter: 0
  Buffers: shared hit=4831 read=142
Planning Time: 0.301 ms
Execution Time: 12.193 ms

enable_seqscan = off 후 인덱스 스캔을 강제하자 1,847ms에서 12ms로 줄었습니다. 통계만 갱신해주면 플래너 스스로 올바른 결정을 내릴 수 있다는 뜻입니다.

-- 해당 테이블의 통계 정보를 즉시 갱신
-- VACUUM ANALYZE와 달리 통계 수집만 수행 (테이블 잠금 없음)
ANALYZE VERBOSE orders;

-- ANALYZE 실행 후 EXPLAIN ANALYZE 재실행 결과
Index Scan using idx_orders_customer_id on orders
  (cost=0.56..5821.32 rows=4790 width=32)
  (actual time=0.038..11.934 rows=4821 loops=1)
  Index Cond: (customer_id = 10042)
  Filter: (status = 'COMPLETED'::text)
  Rows Removed by Filter: 0
  Buffers: shared hit=4831 read=142
Planning Time: 0.289 ms
Execution Time: 12.104 ms

ANALYZE 후 플래너 추정치(4790)가 실제(4821)에 근접했습니다. 실행 시간도 1,800ms → 12ms로 안정됩니다. 명절처럼 데이터 분포가 급격히 변하는 시기에는 autovacuum이 따라가지 못하는 경우가 있습니다. 피크 전후로 주요 테이블에 수동 ANALYZE를 배치에 넣어두는 것이 우리 팀의 대응책이 됐습니다.

---

4. 실전 케이스 2: 조인 순서가 폭발할 때 — Nested Loop vs Hash Join vs Merge Join

세 가지 조인 알고리즘 선택 기준

조인 알고리즘 선택 다이어그램

입력 세트 크기?
    │
    ├─── 작은 테이블 × 큰 테이블 (인덱스 존재)
    │         └─▶ Nested Loop
    │               Inner 테이블을 인덱스로 조회, O(n log m)
    │               work_mem 영향 없음
    │
    ├─── 중간~큰 테이블 × 중간~큰 테이블 (정렬 불필요)
    │         └─▶ Hash Join
    │               작은 쪽으로 해시 테이블 빌드, O(n+m)
    │               work_mem 부족 시 Temp file 생성 → 속도 급락
    │
    └─── 두 테이블 모두 정렬된 상태 (또는 정렬 비용 < 해시 비용)
              └─▶ Merge Join
                    양쪽을 정렬 후 병합, O(n log n + m log m)
                    이미 인덱스 스캔으로 정렬된 경우 추가 정렬 불필요

알고리즘	최적 조건	시간 복잡도	work_mem 의존성
Nested Loop	외부 테이블이 작고 내부 테이블에 인덱스 존재	O(n × log m)	낮음
Hash Join	두 세트 모두 크고 정렬 불필요	O(n + m)	높음 (해시 테이블)
Merge Join	두 세트가 이미 정렬되어 있거나 정렬 비용이 쌀 때	O(n log n + m log m)	중간 (정렬 버퍼)

우리 환경에서 발생했던 케이스는 Hash Join이 선택됐는데 work_mem이 부족해 디스크 Temp 파일이 생성되는 패턴이었습니다.

-- 문제 쿼리: 주문-상품 조인 집계
SELECT
    p.category_id,
    COUNT(DISTINCT o.customer_id) AS unique_buyers,
    SUM(oi.quantity * oi.unit_price) AS revenue
FROM order_items oi
JOIN orders o ON oi.order_id = o.order_id
JOIN products p ON oi.product_id = p.product_id
WHERE o.created_at >= '2026-01-01'
  AND o.status = 'COMPLETED'
GROUP BY p.category_id
ORDER BY revenue DESC;

-- EXPLAIN (ANALYZE, BUFFERS) 출력 — Temp file 발생 케이스
Hash Join  (cost=18420.00..97341.00 rows=2480000 width=24)
           (actual time=1842.321..4198.772 rows=2418324 loops=1)
  Hash Cond: (oi.product_id = p.product_id)
  Buffers: shared hit=8420 read=31248
  ->  Hash Join  (cost=7820.00..52140.00 rows=2480000 width=20)
                 (actual time=812.441..2841.328 rows=2418324 loops=1)
        Hash Cond: (oi.order_id = o.order_id)
        Buffers: shared hit=4210 read=18924
        ->  Seq Scan on order_items oi  (cost=0.00..38420.00 ...)
                                        (actual time=0.022..841.328 ...)
              Buffers: shared hit=2100 read=12842
        ->  Hash  (cost=6420.00..6420.00 rows=112000 width=8)
                  (actual time=799.421..799.421 rows=112847 loops=1)
              Buckets: 131072  Batches: 4  Memory Usage: 4096kB
              Buffers: shared hit=2110 read=6082
  Temp File I/O: read=18420kB written=18420kB    ← 디스크 스필 발생
Planning Time: 1.842 ms
Execution Time: 4201.329 ms

Batches: 4와 Temp File I/O가 핵심 단서입니다. Batches: 1이면 해시 테이블 전체가 메모리에 올라간 것이고, 4이면 4번에 나눠 디스크를 사용했다는 뜻입니다. work_mem을 늘리는 것만으로 해결되는 패턴입니다.

-- 세션 레벨에서 work_mem 조정 (운영 글로벌 설정 변경 전 테스트)
SET work_mem = '256MB';

EXPLAIN (ANALYZE, BUFFERS)
-- (동일 쿼리 재실행)

-- work_mem 256MB 설정 후 재실행
Hash Join  (cost=18420.00..89341.00 rows=2480000 width=24)
           (actual time=924.112..1038.441 rows=2418324 loops=1)
  Hash Cond: (oi.product_id = p.product_id)
  Buffers: shared hit=39668 read=0
  ->  Hash  (cost=6420.00..6420.00 rows=112000 width=8)
            (actual time=312.441..312.441 rows=112847 loops=1)
        Buckets: 131072  Batches: 1  Memory Usage: 8724kB
        Buffers: shared hit=8192 read=0
  Temp File I/O: (없음)
Planning Time: 1.741 ms
Execution Time: 1041.882 ms

Batches: 1로 바뀌고 Temp File I/O가 사라졌습니다. 4,201ms → 1,041ms로 줄었습니다. 단, work_mem을 글로벌로 무작정 올리면 동시 쿼리가 많을 때 메모리를 과도하게 사용할 수 있습니다. 우리 팀은 배치 전용 DB 유저에 ALTER ROLE batch_user SET work_mem = '256MB'를 적용해 배치 세션에만 높은 work_mem이 부여되도록 분리했습니다.

---

5. 실전 케이스 3: LIMIT이 있는데도 느릴 때 — 정렬 최적화와 복합 인덱스 설계

페이지네이션 쿼리는 LIMIT이 붙어 있으니 빠를 것이라고 착각하기 쉽습니다. 하지만 ORDER BY와 함께 쓰이는 LIMIT은 전체 정렬을 먼저 수행한 뒤 상위 N개를 잘라내는 방식으로 동작할 수 있습니다.

-- 상품 목록 최신 순 페이지네이션 쿼리
SELECT product_id, name, price, created_at
FROM products
WHERE category_id = 5
  AND is_active = true
ORDER BY created_at DESC
LIMIT 20;

-- EXPLAIN (ANALYZE, BUFFERS)
Sort  (cost=18420.21..19170.21 rows=300000 width=72)
      (actual time=2841.328..2842.119 rows=20 loops=1)
  Sort Key: created_at DESC
  Sort Method: external merge  Disk: 38420kB   ← 디스크 정렬
  Buffers: shared hit=8420 read=14820
  ->  Seq Scan on products  (cost=0.00..12840.00 rows=300000 width=72)
                            (actual time=0.018..1241.328 rows=298421 loops=1)
        Filter: ((category_id = 5) AND (is_active = true))
        Rows Removed by Filter: 1579
        Buffers: shared hit=8420 read=14820
Planning Time: 0.412 ms
Execution Time: 2851.221 ms

Sort Method: external merge Disk가 보이면 정렬 버퍼가 부족해 디스크를 사용한 것입니다. 여기서 더 큰 문제는 Sort 노드가 플랜 최상단을 차지한다는 점입니다. LIMIT 20을 걸었는데 30만 건 전체를 정렬한 뒤 20개를 잘라냅니다.

복합 인덱스로 Sort 노드 제거

WHERE category_id = 5 AND is_active = true ORDER BY created_at DESC 패턴을 커버하는 복합 인덱스를 만들면, 플래너가 인덱스 순서 자체를 정렬로 활용해 Sort 노드를 없앨 수 있습니다.

-- 복합 인덱스: 필터 컬럼을 앞에, 정렬 컬럼을 뒤에
-- ORDER BY created_at DESC와 인덱스 방향을 맞춥니다.
CREATE INDEX CONCURRENTLY idx_products_category_active_created
ON products (category_id, is_active, created_at DESC)
WHERE is_active = true;  -- 부분 인덱스: is_active=true만 인덱싱

-- 인덱스 생성 후 EXPLAIN (ANALYZE, BUFFERS)
Index Only Scan using idx_products_category_active_created on products
  (cost=0.42..2.14 rows=20 width=72)
  (actual time=0.031..0.091 rows=20 loops=1)
  Index Cond: (category_id = 5)
  Heap Fetches: 0      ← visibility map 완전 활용, 힙 접근 없음
  Buffers: shared hit=5
Planning Time: 0.318 ms
Execution Time: 0.128 ms

2,851ms → 0.128ms. Heap Fetches: 0은 Index Only Scan이 완벽하게 동작하고 있다는 신호입니다. Index Only Scan은 인덱스만으로 쿼리를 완전히 해결할 수 있을 때 선택됩니다. 힙(테이블 본체) 접근 없이 인덱스 페이지만 읽으면 되기 때문에 I/O가 극적으로 줄어듭니다.

단, Index Only Scan이 제대로 동작하려면 visibility map이 최신 상태여야 합니다. Visibility map은 VACUUM이 갱신합니다. 쓰기가 잦은 테이블에서 Heap Fetches가 높다면 VACUUM 주기를 점검해야 합니다.

-- visibility map 상태 확인
SELECT
    relname,
    n_dead_tup,
    last_vacuum,
    last_autovacuum
FROM pg_stat_user_tables
WHERE relname = 'products';

---

6. 실전 케이스 4: 파티션 테이블의 함정 — Partition Pruning이 안 되는 이유

월별 파티션은 대용량 주문·거래 데이터를 다루는 한국 이커머스·핀테크 서비스에서 흔히 채택하는 전략입니다. 12개월 파티션으로 나뉜 테이블에서 특정 월 데이터만 조회하면 당연히 해당 파티션만 스캔해야 합니다. 그런데 그게 항상 되는 게 아닙니다.

Partition Pruning이 작동하는 조건

-- 파티션 기준 컬럼: created_at (RANGE 파티션, 월별)
-- 이 쿼리는 Partition Pruning이 정상 동작합니다
EXPLAIN SELECT * FROM orders
WHERE created_at >= '2026-03-01' AND created_at < '2026-04-01';

-- Pruning 성공: 3월 파티션만 스캔
Append  (cost=0.00..18420.00 rows=842000 width=96)
  ->  Seq Scan on orders_2026_03 orders_1
        (cost=0.00..18420.00 rows=842000 width=96)
        Filter: ((created_at >= '2026-03-01') AND (created_at < '2026-04-01'))
Subplans Removed: 11   ← 11개 파티션 제거됨

Subplans Removed: 11이 보이면 Partition Pruning이 성공한 것입니다. 12개 파티션 중 11개가 제거되고 해당 파티션 1개만 스캔합니다. Subplans Removed 필드는 플래닝 단계(static pruning)에서 제거된 파티션 수를 나타내며, PostgreSQL 10 이상에서 출력됩니다. 런타임 단계(runtime pruning)에서 제거된 경우에는 이 필드 대신 실행 계획 노드 자체가 표시되지 않습니다.

Pruning이 실패하는 패턴 — 파라미터 바인딩 방식의 함정

-- 애플리케이션에서 PreparedStatement로 실행하는 경우
-- $1, $2 파라미터로 날짜를 바인딩
PREPARE monthly_query AS
SELECT * FROM orders
WHERE created_at >= $1 AND created_at < $2;

EXPLAIN EXECUTE monthly_query('2026-03-01', '2026-04-01');

-- Pruning 실패: 전체 파티션 Append
Append  (cost=0.00..221040.00 rows=10104000 width=96)
  ->  Seq Scan on orders_2025_05 orders_1  ...
  ->  Seq Scan on orders_2025_06 orders_2  ...
  -- ... (12개 파티션 전부 등장)
  ->  Seq Scan on orders_2026_04 orders_12 ...
Subplans Removed: 0   ← Pruning 전혀 안 됨

Subplans Removed: 0. 12개 파티션 전부를 스캔합니다. 이것이 PreparedStatement와 Partition Pruning 사이의 고전적 충돌입니다.

원인은 플랜 캐싱에 있습니다. PREPARE 시점에 PostgreSQL은 파라미터 값을 모르는 상태로 제네릭 플랜을 만들어 캐시합니다. $1, $2의 실제 값을 알 수 없으니 어느 파티션을 제거할지 판단하지 못하는 것입니다.

-- 해결책 1: EXECUTE 플랜 재수립 강제
-- plan_cache_mode 파라미터로 제어 (PostgreSQL 12+)
SET plan_cache_mode = 'force_custom_plan';

-- 해결책 2: 동적 SQL로 파라미터를 리터럴로 바인딩
-- (ORM 레벨에서 조정 필요)

-- 해결책 3: enable_partition_pruning 재확인
SHOW enable_partition_pruning;  -- 기본값: on 확인

plan_cache_mode = 'force_custom_plan'을 설정하면 PreparedStatement도 매 실행마다 파라미터를 보고 플랜을 수립합니다. 커스텀 플랜 수립 비용이 추가되지만, 파티션 테이블처럼 Pruning 효과가 큰 경우에는 이 비용이 수백 배 빠른 실행 시간으로 상쇄됩니다.

파티션 상황을 Append 노드로 파악하는 방법도 알아두면 좋습니다. EXPLAIN 출력에서 Append 노드 아래에 파티션별 Seq Scan 또는 Index Scan 자식이 나열됩니다. 자식의 수 = 스캔하는 파티션 수입니다. 예상보다 자식이 많다면 Pruning이 덜 된 것입니다.

---

7. PgBadger로 슬로우 쿼리 리포트 자동화하기

EXPLAIN ANALYZE는 이미 느리다고 의심되는 쿼리를 들여다볼 때 씁니다. 반면 "오늘 가장 많은 시간을 잡아먹은 쿼리가 무엇인가"를 파악하려면 로그 전체를 파싱해야 합니다. PgBadger(github.com/darold/pgbadger)는 PostgreSQL 로그를 파싱해 슬로우 쿼리 리포트를 HTML로 생성하는 Perl 스크립트입니다. 설치가 간단하고 의존성이 거의 없어 운영 서버에 바로 올릴 수 있습니다.

postgresql.conf 로그 설정

PgBadger가 올바르게 파싱하려면 로그 형식이 맞아야 합니다.

# postgresql.conf — PgBadger 호환 설정
log_destination = 'stderr'
logging_collector = on
log_directory = '/var/log/postgresql'
log_filename = 'postgresql-%Y-%m-%d.log'
log_rotation_age = 1d
log_rotation_size = 0

# PgBadger 파싱에 필수: %t(타임스탬프), %p(PID), %d(DB명),
#                       %u(유저명), %a(앱명), %h(호스트)
log_line_prefix = '%t [%p]: user=%u,db=%d,app=%a,client=%h '

log_min_duration_statement = 1000     # 1초 이상 쿼리 기록
log_checkpoints = on
log_connections = off                  # 커넥션 로그는 대용량에서 제외
log_disconnections = off
log_lock_waits = on
log_temp_files = 0                     # 모든 Temp file 기록
log_autovacuum_min_duration = 0

# 한국 환경: KST 기준 타임스탬프
log_timezone = 'Asia/Seoul'

# PgBadger가 lc_messages로 언어를 자동 감지 — 반드시 영어로
lc_messages = 'en_US.UTF-8'

lc_messages = 'en_US.UTF-8'은 중요합니다. PgBadger는 영어 로그 메시지를 파싱합니다. ko_KR.UTF-8로 설정하면 에러 메시지가 한글로 찍혀 PgBadger가 인식하지 못합니다.

HTML 리포트 생성

# PgBadger 설치 (Debian/Ubuntu 계열)
sudo apt-get install pgbadger

# 단일 로그 파일로 HTML 리포트 생성
# --format은 입력 로그 형식(stderr/csv/syslog 등)을 지정합니다.
# 출력 형식(HTML/JSON/텍스트)은 --outfile의 확장자로 자동 결정됩니다.
pgbadger \
  --prefix '%t [%p]: user=%u,db=%d,app=%a,client=%h ' \
  --outfile /var/www/html/pgbadger/report_$(date +%Y%m%d).html \
  --format stderr \
  /var/log/postgresql/postgresql-$(date +%Y-%m-%d).log

# 최근 7일치 로그를 한꺼번에 파싱
pgbadger \
  --prefix '%t [%p]: user=%u,db=%d,app=%a,client=%h ' \
  --outfile /var/www/html/pgbadger/weekly_report.html \
  --format stderr \
  /var/log/postgresql/postgresql-2026-04-*.log

리포트에는 슬로우 쿼리 TOP 10, 쿼리 빈도 TOP 10, 시간대별 쿼리 분포, Temp file 발생 쿼리, Lock wait 이벤트 등이 포함됩니다.

PgBadger 리포트 주요 섹션	포함 정보	튜닝 활용법
Slowest queries	실행 시간 최대값 기준 정렬	즉시 EXPLAIN ANALYZE 대상 식별
Time consuming queries	누적 실행 시간 기준 정렬	빈도 × 시간이 큰 쿼리 우선 튜닝
Most frequent queries	호출 횟수 기준 정렬	캐싱·인덱스 추가 우선순위 결정
Queries per hour	시간대별 히트맵	피크 타임 패턴 식별, 배치 시간 조정
Temporary files	Temp file 발생 쿼리 목록	work_mem 조정 대상 식별
Lock waits	Lock 대기 이벤트	트랜잭션 분리 수준·인덱스 잠금 진단

Cron + Slack 알럿 연동 Bash 스크립트

#!/bin/bash
# /usr/local/bin/pgbadger-daily-report.sh
# 매일 KST 오전 7시(UTC 22:00 전날) cron 실행
# crontab: 0 22 * * * /usr/local/bin/pgbadger-daily-report.sh

set -euo pipefail

PGLOG_DIR="/var/log/postgresql"
REPORT_DIR="/var/www/html/pgbadger"
REPORT_DATE=$(TZ="Asia/Seoul" date +%Y-%m-%d)
LOG_FILE="${PGLOG_DIR}/postgresql-${REPORT_DATE}.log"
REPORT_FILE="${REPORT_DIR}/report_${REPORT_DATE}.html"
SLACK_WEBHOOK="${PGBADGER_SLACK_WEBHOOK:-}"  # 환경변수에서 주입
LOG_PREFIX='%t [%p]: user=%u,db=%d,app=%a,client=%h '

# 로그 파일 존재 여부 확인
if [[ ! -f "${LOG_FILE}" ]]; then
  echo "[ERROR] 로그 파일 없음: ${LOG_FILE}" >&2
  exit 1
fi

# PgBadger 리포트 생성
pgbadger \
  --prefix "${LOG_PREFIX}" \
  --outfile "${REPORT_FILE}" \
  --format stderr \
  --timezone 9 \
  "${LOG_FILE}"

# 슬로우 쿼리 TOP 3 텍스트 추출 (pg_stat_statements 조회)
SLOW_QUERIES=$(psql -U postgres -d "${PGDB:-app}" -At -c "
  SELECT
    round(mean_exec_time::numeric, 0) || 'ms | x' || calls || ' | ' ||
    left(query, 80)
  FROM pg_stat_statements
  WHERE calls > 5
  ORDER BY mean_exec_time DESC
  LIMIT 3;
")

# Slack 알럿 발송
if [[ -n "${SLACK_WEBHOOK}" ]]; then
  REPORT_URL="https://monitoring.example.internal/pgbadger/report_${REPORT_DATE}.html"
  PAYLOAD=$(cat <<EOF
{
  "text": "*[PgBadger 일일 리포트] ${REPORT_DATE} (KST)*
\`\`\`${SLOW_QUERIES}\`\`\`
리포트: ${REPORT_URL}"
}
EOF
)
  curl -sf -X POST \
    -H "Content-Type: application/json" \
    -d "${PAYLOAD}" \
    "${SLACK_WEBHOOK}" || echo "[WARN] Slack 알럿 발송 실패" >&2
fi

echo "[OK] PgBadger 리포트 생성 완료: ${REPORT_FILE}"

이 스크립트를 crontab에 등록하면 매일 아침 출근 전에 슬랙으로 전날 슬로우 쿼리 현황이 올라옵니다. 운영 팀이 장애가 터진 뒤에야 쿼리를 들여다보는 게 아니라, 일상적인 모니터링 루틴 안에서 미리 문제를 잡을 수 있게 됩니다.

---

8. 우리가 슬로우 쿼리를 길들이며 배운 것 — 실무 체크리스트

새벽 2시 알럿 이후 1년 가까이 슬로우 쿼리와 씨름하면서, 우리 팀은 "튜닝은 일회성 이벤트가 아니라 지속적인 관찰과 개입의 반복"이라는 결론에 이르렀습니다. 코드 배포보다 데이터 분포 변화가 더 자주 쿼리 플랜을 망가뜨립니다. 명절·세일 시즌처럼 트래픽이 급변하는 환경이라면 더욱 그렇습니다.

아래는 우리 팀이 현재 운영 중인 실무 체크리스트입니다.

• pg_stat_statements 기반 주간 리뷰: 매주 월요일 total_exec_time 상위 10개 쿼리를 팀 채널에 공유합니다. "지난 주 대비 새로 올라온 쿼리가 있는가"를 확인하는 것만으로 배포 직후 성능 회귀를 조기에 잡을 수 있습니다.

• 피크 시즌 전 주요 테이블 수동 ANALYZE: 명절·블랙프라이데이·연말 정산 등 트래픽이 급변하는 이벤트 전일 밤에 핵심 테이블 5~10개를 ANALYZE VERBOSE로 강제 갱신합니다. Autovacuum이 따라가지 못하는 구간을 수동으로 메웁니다.

• EXPLAIN ANALYZE를 트랜잭션으로 감싸는 습관: UPDATE·DELETE 쿼리의 실행 계획을 확인할 때는 항상 BEGIN; ... ROLLBACK; 패턴을 씁니다. 이것은 팀 전체 코딩 가이드라인에 한 줄로 명시해뒀습니다.

• 복합 인덱스 설계 시 ORDER BY 방향을 포함: WHERE의 필터 컬럼을 앞에 두고, ORDER BY 컬럼과 방향(ASC/DESC)을 뒤에 맞춥니다. 페이지네이션 쿼리에서 Sort 노드가 사라지면 LIMIT의 성능 효과가 제대로 발휘됩니다.

• 파티션 테이블 도입 시 PreparedStatement 프루닝 테스트 선행: ORM이 PreparedStatement를 기본으로 사용하는 경우, plan_cache_mode와 Partition Pruning 동작을 스테이징에서 반드시 검증합니다. "파티션이라서 당연히 빠를 것"이라는 기대가 Pruning 실패로 오히려 더 느려지는 케이스를 실제로 겪었습니다.

• Buffers: shared read가 높은 쿼리를 I/O 병목 1순위로: shared hit은 캐시 히트, shared read는 디스크(또는 OS 페이지 캐시) 읽기입니다. shared read가 전체 블록의 20%를 넘는 쿼리는 인덱스 추가나 shared_buffers 조정 대상입니다. 단, shared_buffers는 전체 메모리의 25% 정도를 초과하면 효과가 줄어들기 시작합니다.

PostgreSQL 쿼리 튜닝은 EXPLAIN ANALYZE 출력 한 줄 한 줄을 정확히 읽는 것에서 시작합니다. 숫자를 감이 아니라 근거로 읽기 시작하면, 튜닝의 방향이 보이고 불필요한 인덱스를 만들지 않게 됩니다. 그리고 그것이 쌓이면 새벽 2시 알럿 없는 명절 밤이 됩니다.

---

Sources:

• PostgreSQL 16 EXPLAIN Documentation
• PgBadger GitHub Repository