[PostgreSQL 10/12] 느린 SQL 조사하기: EXPLAIN·pg_stat_statements·auto_explain

이 글에서 다룰 주제

• 증거: 누적 부담과 간헐적인 지연은 어디에서 확인하는가?
• 계측: 로그 임계값과 실제 통계 수집 범위는 어떻게 다른가?
• 해석: rows·loops·buffers를 튜닝 가설로 어떻게 연결하는가?

주요 단어 · EXPLAIN · ANALYZE · Rows/Loops · Buffers · pg_stat_statements · auto_explain

---

평균 실행 시간만 보면 간헐적인 느린 요청을 놓치고, 가장 느린 한 번만 보면 서비스 전체의 개선 우선순위를 잘못 잡을 수 있다. 필요한 것은 집계 통계와 개별 실행의 계획을 연결하는 일이다. EXPLAIN, pg_stat_statements, auto_explain은 이 과정에서 서로 다른 증거를 제공한다.

실행 계획은 SQL을 어떤 연산 순서와 접근 경로로 처리할지 보여준다. auto_explain은 조건에 해당하는 실행의 계획을 서버 로그에 남기는 모듈이다.

자료와 예제 기준 — PostgreSQL 18을 중심으로 개인 학습 노트를 재구성했다. SQL·실행 계획·설정값은 설명 및 재현용 예제이며 이 글을 위해 운영 DB에서 새로 측정한 결과는 아니다. DDL/DML 예제는 독립적인 테스트 환경에서 사용한다.

1. 개념과 필요성

auto_explain은 조건에 해당하는 SQL 실행의 실행 계획을 PostgreSQL 서버 로그에 남기는 진단 모듈이다. 자동으로 인덱스를 만들거나 SQL을 고치는 기능은 아니다.

평소 30ms인 주문 조회가 특정 고객에게만 5초 걸리는 상황을 생각해 보자. 개발자가 나중에 같은 SQL을 실행하면 다시 빨라질 수 있다. 바인딩 값, 고객별 데이터 분포, 캐시, 동시 부하, 통계 및 선택된 계획이 달라졌기 때문이다.

수동 재현만으로는 장애 시점의 상태를 복원하기 어렵다. auto_explain은 문제가 발생한 실행의 계획을 기록해 사후 조사 근거를 남긴다.

특히 유용한 상황은 다음과 같다.

• 동일한 SQL이 특정 파라미터에서만 느리다.
• 배치와 온라인 요청이 겹치는 시간대에 성능이 악화된다.
• ORM이 생성한 복잡한 SQL의 실제 동작을 확인해야 한다.
• 함수 내부의 어떤 SQL이 느린지 조사해야 한다.
• 통계 또는 데이터 분포 변화 이후 계획 선택이 달라졌는지 확인하고 싶다.

기록된 계획은 원인 분석의 증거이며, 지연의 모든 원인을 단독으로 확정하는 자료는 아니다.

2. 관련 도구의 역할

도구	주요 질문	제공 정보	구분할 점
EXPLAIN	어떻게 실행할 예정인가?	예상 계획·행 수·비용	일반적으로 대상 SQL을 실행하지 않음
EXPLAIN ANALYZE	직접 실행해 보니 어떻게 동작했나?	실제 행 수·반복 횟수·실행 통계	SQL을 실제로 실행하므로 쓰기 SQL은 데이터 변경 가능
log_min_duration_statement	어떤 SQL이 오래 걸렸나?	SQL과 소요 시간	실행 계획은 제공하지 않음
pg_stat_statements	어떤 쿼리 유형의 누적 부담이 큰가?	호출 수·누적 실행 시간·평균 등	개별 실행 계획 저장소가 아님
auto_explain	조건에 해당한 그 실행은 어떤 계획이었나?	개별 실행 계획과 선택적 실제 통계	계측·로그 출력 비용과 샘플 누락 존재

실무 분석 흐름은 다음처럼 구성할 수 있다.

1. pg_stat_statements에서 누적 시간이 큰 쿼리 유형을 찾는다.
2. auto_explain 로그에서 해당 쿼리의 느린 실행 사례를 조사한다.
3. 통계·인덱스·쿼리 구조·메모리 설정에 대한 가설을 세운다.
4. 통제된 환경에서 EXPLAIN ANALYZE로 변경 전후를 비교한다.
5. 실제 트래픽에서 지연과 자원 사용이 개선되었는지 확인한다.

평균 시간만으로는 간헐적 지연을 설명하기 어렵고, 가장 느린 한 번만으로는 전체 서비스의 개선 우선순위를 정하기 어렵다. 집계와 개별 실행을 함께 본다.

3. 내부 동작과 성능 비용

auto_explain은 PostgreSQL Executor의 훅에 연결되어 실행 정보를 수집한다. 느린 쿼리를 찾은 뒤 SQL을 한 번 더 실행하는 방식이 아니다. 애플리케이션이 요청한 원래 실행을 관찰한다.

로그 임계값과 계측 대상은 다르다

아래 설정은 1초 이상인 실행의 계획을 기록한다.

auto_explain.log_min_duration = '1s'
auto_explain.sample_rate = 1
auto_explain.log_analyze = on
auto_explain.log_timing = on

하지만 SQL이 1초를 넘을지는 실행 전에 알 수 없다. 실제 통계를 얻으려면 실행 중부터 계측해야 하므로, 로그에 남지 않는 짧은 실행에도 비용이 발생한다.

특히 log_timing은 계획 노드의 시간을 반복 측정한다. 실행 노드 호출이 많으면 시간 측정 자체의 부담이 커질 수 있다. log_timing을 끄면 실제 행 수와 반복 횟수는 확보하면서 노드별 시간 측정을 줄일 수 있다. 다만 행 수·버퍼 계측 등의 비용까지 사라지는 것은 아니다.

샘플링의 의미

sample_rate = 0.1은 실행 전에 약 10%를 계측 대상으로 선택한다는 의미다. 느린 실행을 모두 수집한 후 로그만 10% 남기는 방식이 아니다.

예를 들어 임계값 1초, 샘플링 10%라면 다음 두 조건을 모두 만족해야 기록된다.

• 그 실행이 샘플로 선택되었다.
• 그 실행의 측정 시간이 1초 이상이었다.

따라서 샘플링을 낮추면 부하와 로그량을 줄일 수 있지만, 희귀한 지연을 놓칠 수 있다. 기록된 건수를 전체 지연 발생 건수로 그대로 해석하면 안 된다.

4. 주요 설정

핵심 설정

설정	기본값	의미	판단 기준
auto_explain.log_min_duration	-1	계획 기록의 최소 실행 시간	-1은 비활성, 0은 모든 대상 실행 기록
auto_explain.log_analyze	off	실제 행 수·반복 횟수 등 수집	원인 분석에 유용하나 계측 비용 발생
auto_explain.log_timing	on	노드별 시간 측정	초기 운영 관측에서는 off 고려
auto_explain.log_buffers	off	버퍼 사용 통계	log_analyze가 on이어야 효과 있음
auto_explain.sample_rate	1	계측 대상 선택 비율	0~1, 희귀 사례 확보와 비용의 균형
auto_explain.log_format	text	계획 출력 형식	text·json·xml·yaml

시간은 '500ms', '1s'처럼 단위를 명시하면 의도가 명확하다. log_timing을 꺼도 전체 실행 시간 정보가 사라지는 것은 아니다.

조사 목적에 따라 추가할 설정

설정	목적	주의점
log_nested_statements	함수 내부 SQL까지 조사	기본 off, 중첩 실행으로 로그가 늘어날 수 있음
log_wal	WAL 생성량 조사	log_analyze 필요, WAL 생성량은 commit flush 대기 시간과 다름
log_triggers	트리거 실행 통계	log_analyze 필요
log_settings	기본값과 다른 계획 관련 설정 표시	모든 서버 설정을 덤프하는 기능은 아님
log_verbose	계획의 상세 정보 확대	로그 크기 증가
log_parameter_max_length	바인딩 파라미터 기록 길이 제한	0은 파라미터 값 기록 비활성화, 완전한 마스킹 기능은 아님
log_level	계획 로그 레벨	기본 LOG, 수집 경로의 필터와 함께 확인

파라미터 값을 제한해도 SQL 리터럴이나 실행 계획 표현식에 값이 남을 수 있다. 로그 데이터의 실제 형태를 확인해 접근 권한과 보존 정책을 정한다.

5. 세션 단위 실습

서버에 auto_explain 모듈이 설치되어 있고 필요한 관리자 권한이 있다는 전제다. 관리형 DB는 해당 서비스의 확장 및 파라미터 설정 절차를 따른다.

auto_explain은 SQL 함수를 만드는 확장이 아니므로 CREATE EXTENSION 대신 LOAD 또는 preload 설정으로 로드한다.

-- 별도 테스트 연결에서 실행
LOAD 'auto_explain';

-- 테스트에서는 실행 계획을 빠짐없이 확인
SET auto_explain.log_min_duration = '0ms';
SET auto_explain.sample_rate = 1;

SET auto_explain.log_analyze = on;
SET auto_explain.log_timing = off;
SET auto_explain.log_buffers = on;
SET auto_explain.log_format = 'text';

SELECT count(*)
FROM pg_catalog.pg_class;

-- 조사 종료 후 계획 기록 비활성화
SET auto_explain.log_min_duration = -1;

로그는 일반 SELECT 결과 창이 아니라 PostgreSQL 서버 로그에서 확인한다. 파일·표준 오류·관리형 서비스 로그 중 어디로 전달되는지는 서버 구성에 따른다.

로그가 없으면 다음을 점검한다.

1. SQL을 실행한 동일한 서버 세션에 모듈이 로드되어 있는가?
2. log_min_duration이 -1로 남아 있지 않은가?
3. 샘플링 대상에서 제외되지 않았는가?
4. 실행 시간이 임계값에 도달했는가?
5. 조회 중인 로그가 실제 서버·인스턴스의 로그인가?
6. 수집 시스템에서 LOG 레벨 또는 여러 줄 메시지를 누락하지 않는가?

6. 운영 적용과 연결 풀

다음 수치는 보편적인 정답이 아니라 부하를 확인하며 조정할 출발점이다.

# postgresql.conf
# 기존 목록이 있다면 덮어쓰지 않고 auto_explain을 추가한다.
session_preload_libraries = 'auto_explain'

auto_explain.log_min_duration = '1s'
auto_explain.sample_rate = 0.1

auto_explain.log_analyze = on
auto_explain.log_timing = off
auto_explain.log_buffers = on
auto_explain.log_format = 'json'

로드 방법과 적용 범위

방법	적용 범위	적용 시 유의점
LOAD 'auto_explain'	현재 서버 세션	다른 애플리케이션 연결에는 적용되지 않음
session_preload_libraries	새 서버 세션	설정 reload 후 새 연결에서 로드
shared_preload_libraries	서버 시작 시 로드	목록 변경에는 서버 재시작 필요

session_preload_libraries를 바꾼 뒤 reload만 하면 기존 연결에 모듈이 자동으로 생기는 것은 아니다. 애플리케이션 풀의 연결 교체를 계획해야 한다.

PgBouncer를 사용한다면 클라이언트 연결과 실제 PostgreSQL 서버 연결을 구분한다. 클라이언트가 다시 접속해도 기존 서버 연결이 재사용될 수 있다. 또한 트랜잭션 풀링 환경에서는 세션 단위 LOAD·SET 실습을 일반 애플리케이션 경유 연결에서 그대로 수행하기보다, 대상 서버 세션이 명확한 직접 연결에서 검증하는 편이 낫다.

단계적 적용 예시

단계	목적	설정 방향
테스트	로그 형식과 수집 경로 확인	임계값 0, sample_rate 1, 별도 연결
제한 관측	운영 부하 파악	높은 임계값, 낮은 샘플링, timing off
집중 조사	희귀 지연 근거 확보	대상과 시간을 제한하고 샘플링 확대
조사 종료	불필요한 계측 축소	원래 설정 복구 또는 log_min_duration -1

CPU, 처리량, p95·p99 지연, 로그 증가량, 로그 수집 지연을 함께 비교한다. log_analyze를 끈 모드는 실제 행 수를 얻지 못하지만 계측 부담을 줄이는 선택지가 된다.

7. 실행 계획 읽기

아래 로그는 설명을 위한 가상 예시다.

LOG: duration: 1842.300 ms  plan:

Seq Scan on orders
  (cost=0.00..250000.00 rows=100 width=80)
  (actual rows=120000 loops=1)

  Filter: (customer_id = 42)
  Rows Removed by Filter: 9880000
  Buffers: shared hit=20000 read=80000

관찰	해석	다음 조사
예상 rows=100, 실제 120000	행 수 과소 추정	통계 최신성·분포 편향·조건 간 상관관계
Seq Scan	순차 스캔 선택	반환 비율·테이블 크기·인덱스 유무
약 988만 행 필터 제거	읽은 뒤 버린 행이 많음	조건과 인덱스 구성
shared read=80000	shared buffers에 없어 블록 읽기 발생	읽기 작업량·I/O 시간·캐시 상태

rows와 loops

rows는 해당 노드가 출력하는 행 수이며, 읽어 본 전체 행 수와 같지 않을 수 있다. 일반적인 반복 실행 노드에서 actual rows는 반복당 평균이고 loops는 반복 횟수다.

예를 들어 actual rows=20, loops=1000이면 해당 노드의 총 출력량은 대략 20,000행으로 이해한다. 병렬 계획과 워커별 통계는 별도로 구분해서 읽는다.

cost는 밀리초가 아니다

cost는 옵티마이저의 비용 모델 단위다. cost=1000을 1초라고 해석하지 않는다. 예상 비용과 실제 시간은 서로 다른 정보다.

Seq Scan은 항상 나쁜가?

아니다. 작은 테이블이나 대부분의 행을 반환하는 조회에서는 순차 스캔이 합리적이다. 인덱스가 있어도 랜덤 접근 비용과 반환 비율 때문에 순차 스캔이 선택될 수 있다.

버퍼 통계의 함정

• shared hit: PostgreSQL shared buffers에서 블록을 찾은 접근.
• shared read: shared buffers에 없어 블록을 읽은 접근. OS 캐시에서 제공되었을 수 있으므로 모두 물리 디스크 접근은 아니다.
• 버퍼 접근 횟수는 고유 블록 수가 아니다. 같은 블록의 반복 접근이 포함될 수 있다.
• 상위 노드의 버퍼 수치에는 하위 노드 작업이 포함될 수 있다. 트리의 모든 수치를 더하면 중복 계산할 수 있다.
• 버퍼 수치 자체가 I/O 지연 시간을 알려 주지는 않는다.

이 예시에서 세울 가설

“특정 고객에게 데이터가 집중되어 실제 결과가 예상보다 많고, 많은 행을 읽고 버리는 작업이 발생했다.”

이것은 원인 후보다. 인덱스 부재 또는 통계 부족을 확정한 결과가 아니다. 테이블 정의, 데이터 분포, 다른 고객의 실행, 실제 버퍼·시간 통계를 함께 확인한다.

8. 진단에서 튜닝으로 연결

로그의 단서	가능한 원인	확인 또는 개선 방향
예상/실제 행 수의 큰 차이	오래된 통계, 편향, 조건 간 상관	ANALYZE, 통계 수준, 확장 통계 검토
Nested Loop 안쪽의 큰 loops	바깥쪽 결과 과소 추정, 반복 접근 증가	조인 순서·행 수 추정·조인 키 인덱스
필터로 대량 제거	접근 경로와 조건 불일치	복합/부분 인덱스 및 쿼리 조건 검토
정렬의 디스크 사용	작업량 대비 정렬 메모리 부족	반환량·정렬 인덱스·세션별 work_mem
쓰기에서 WAL 생성량 큼	많은 행 변경, 인덱스 유지 비용 등	불필요한 UPDATE·인덱스·배치 방식
계획 작업량은 작지만 오래 걸림	잠금·자원 경합 등	wait event·잠금·호스트 지표와 교차 확인

메모리 부족으로 정렬이 디스크로 내려갔다고 work_mem을 전역으로 크게 올리는 것은 위험하다. work_mem은 전체 서버의 단일 예산이 아니라 여러 작업과 동시 연결에서 사용될 수 있다. 실제 동시성을 고려해 변경한다.

WAL 생성량이 많다는 사실만으로 commit의 fsync 지연이나 checkpoint 문제를 확정할 수 없다. auto_explain의 실행 계획, DB 대기 상태, WAL·스토리지 지표는 서로 보완하는 증거다.

권장 조사 순서

1. 느린 실행의 시간·DB·사용자·애플리케이션·SQL을 확보한다.
2. 계획에서 예상/실제 행 수와 반복량을 먼저 확인한다.
3. 버퍼·정렬·조인·WAL 등 큰 작업량을 찾는다.
4. 같은 시간의 잠금·CPU·I/O·동시 실행을 확인한다.
5. 원인 후보별로 최소 변경을 적용한다.
6. 변경 전후 계획과 실제 서비스 성능을 비교한다.

auto_explain은 종료 시점에 계획을 기록하므로 현재 오래 실행 중인 쿼리를 실시간으로 관찰하는 도구를 대체하지 않는다. 취소·오류로 끝난 모든 실행에 정상 종료와 같은 로그가 남는다고 가정해서도 안 된다.

9. 관측 시스템과 연결

아래는 구성 제안이며, 실제 배포를 수행한 결과는 아니다.

로그에서는 개별 실행의 계획을 보고, 메트릭에서는 같은 시간대 CPU·연결 수·처리량·지연 변화를 본다.

log_format='json'은 실행 계획의 형식을 지정한다. PostgreSQL의 전체 서버 로그가 자동으로 JSON 로그로 바뀐다는 의미는 아니다. 바깥 로그 포맷과 계획 본문의 포맷을 구분하여 파서를 설계한다.

수집 설계에서는 다음을 고려한다.

• 시간, 인스턴스, 데이터베이스, 애플리케이션, 프로세스 등 조사에 필요한 문맥을 보존한다.
• 여러 줄 계획을 중간에서 분리하거나 잘라 버리지 않도록 한다.
• SQL 원문과 실행 계획 전체를 Loki 라벨로 만들지 않는다. 본문 또는 적절한 메타데이터로 저장한다.
• 바인딩 값의 노출과 로그 보존 비용을 확인한다.
• 샘플링 및 임계값을 기록해 수집 편향을 해석할 수 있게 한다.

애플리케이션 trace와 DB 로그의 자동 연결은 별도 설계다. application_name만으로 개별 요청 trace가 항상 구분되는 것은 아니다.

10. 운영 체크리스트와 복습

적용 전후 체크리스트

• 사용 PostgreSQL 버전과 모듈 지원 여부 확인
• 별도 연결에서 LOAD와 로그 출력 확인
• 서비스 목표에 맞는 임계 시간 결정
• 샘플링 누락을 수용할지 결정
• log_analyze 계측 비용 확인
• 초기에는 log_timing off 검토
• 연결 풀의 실제 서버 연결 교체 여부 확인
• 계획 로그 파싱·절단·여러 줄 처리 확인
• SQL·파라미터 접근 권한과 보존 정책 확인
• CPU·처리량·p95/p99·로그량을 도입 전후 비교
• 조사 종료 시 설정 복구

자주 하는 오해

오해	정확한 이해
auto_explain이 자동 튜닝한다	실행 계획을 수집하는 진단 도구다
느린 SQL을 다시 실행한다	원래 실행을 계측한다
로그에 없으면 계측 비용도 없다	임계값 미만의 샘플도 실행 중 계측될 수 있다
timing off면 실행 정보가 없다	실제 행 수·반복 횟수·전체 시간 정보를 활용할 수 있다
read는 모두 디스크 I/O다	OS 캐시를 통한 읽기도 가능하다
Seq Scan은 무조건 문제다	반환 비율과 접근 비용에 따라 최선일 수 있다
계획 JSON이면 로그 전체가 JSON이다	계획 포맷과 서버 로그 포맷은 별개다
reload하면 기존 연결에도 모듈이 로드된다	session preload는 새 서버 세션에 적용된다

복습 질문

1. log_min_duration을 높여도 계측 비용이 남는 이유는 무엇인가?
2. sample_rate를 낮추면 희귀 지연 분석에 어떤 한계가 생기는가?
3. 예상 rows와 실제 rows가 크게 다를 때 무엇부터 확인할 것인가?
4. shared hit가 높아도 SQL이 느릴 수 있는 이유는 무엇인가?
5. 잠금 대기와 커넥션 풀 대기를 조사하려면 어떤 추가 정보가 필요한가?

이어서 학습할 주제

• EXPLAIN ANALYZE의 cost·rows·actual time·loops와 병렬 계획 해석
• pg_stat_statements의 집계 시간 구간과 쿼리 우선순위 선정
• ANALYZE·통계 대상 수·CREATE STATISTICS와 행 수 추정
• Prepared Statement의 generic plan·custom plan과 데이터 편향
• auto_explain 로그와 Loki·Grafana의 연계

---

자료 기준과 참고 문서

개인 PostgreSQL 학습 노트를 바탕으로 정리했다. 버전이나 설정에 따른 조건은 본문에 덧붙였다.

• auto_explain
• EXPLAIN
• 계획 해석
• pg_stat_statements
• 누적 통계

이어서 읽기 · ← 이전 편 · 다음 편 → · 전체 시리즈 목차