EXPLAIN ANALYZE — 무엇을 어떤 순서로 볼 것인가

한 줄 요약

실행 계획을 읽는다는 것은 노드 이름을 훑는 일이 아니라 옵티마이저의 예측과 실제 결과 사이의 괴리를 찾는 일이다.

왜 이게 필요했나

느린 쿼리에 EXPLAIN ANALYZE 를 붙였는데 화면을 가득 채운 괄호 속 숫자를 한참 보다가 "Seq Scan 이 보이니 인덱스를 만들자"로 건너뛰는 일이 흔하다. 그 결론이 맞을 때도 있지만, 계획이 알려 주려던 것은 대개 다른 이야기다.

괴리가 없다면 옵티마이저는 자기가 아는 정보 안에서 최선을 골랐다는 뜻이고 남은 병목은 물리적인 문제다. 괴리가 크다면 옵티마이저는 틀린 전제 위에서 정확하게 계산한 것이고, 손볼 대상은 쿼리가 아니라 통계다.

어떻게 동작하나

EXPLAIN 은 계획만 세우고 EXPLAIN ANALYZE 는 실제로 실행한다. 그래서 EXPLAIN ANALYZE UPDATE ... 는 진짜로 UPDATE 를 수행한다. 쓰기 쿼리를 분석할 때는 트랜잭션으로 감싸고 롤백해야 한다.

읽는 순서는 가장 깊이 들여쓰인 노드부터다. 들여쓰기가 깊을수록 먼저 실행되고, 부모 노드는 자식이 끝난 뒤에 완성된다. 그리고 부모의 actual time 은 자식의 시간을 포함한 누적값이다. 이 사실을 모르면 "조인이 131ms 나 걸린다"는 잘못된 결론에 도달한다.

cost=1842.00..24310.55 에서 앞은 첫 행까지, 뒤는 마지막 행까지의 비용이다. 단위는 밀리초가 아니라 순차 페이지 한 장 읽기를 1.0 으로 놓은 임의 단위다. 그래서 다른 쿼리의 cost 와 비교하는 것은 의미가 없고, "cost 가 얼마를 넘으면 위험" 같은 기준도 근거가 없다.

진짜 봐야 할 것은 같은 노드 안의 두 숫자다.

->  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행, 실제 48만 행. 4만 배 이상 틀렸다. 옵티마이저는 "1행만 나올 테니 중첩 루프로 붙이면 되겠다"고 판단했을 것이고, 그 전제가 무너지며 안쪽 노드를 48만 번 반복하게 된다. 이때 고칠 것은 조인 힌트가 아니라 통계다.

loops 는 반드시 곱해서 봐야 한다. 표시된 시간과 행 수는 1회 실행 기준 평균이다. actual time=0.011 rows=4 loops=52310 이면 총 시간은 약 575ms, 총 행은 약 20만 행이다. 계획 어디에도 575라는 숫자는 적혀 있지 않으므로 곱셈을 직접 해 보지 않으면 병목을 지나친다.

BUFFERS 옵션이 없는 EXPLAIN ANALYZE 는 반쪽이다. shared hit 은 버퍼 캐시에서 찾은 블록, shared read 는 캐시 밖에서 읽은 블록이다. 같은 쿼리가 어제는 20ms, 오늘은 900ms 인 이유는 대개 계획이 아니라 캐시에 있다.

현장에서 만나는 모습

Filter 와 Index Cond 의 차이가 중요하다. Filter 는 행을 읽은 뒤에 버리는 것이고 Index Cond 는 애초에 읽지 않는 것이다. Rows Removed by Filter 밑에 큰 숫자가 있으면 그 조건을 인덱스로 올릴 기회가 있다는 신호다.

Hash Join 에서 Batches 가 1이 아니면 해시 테이블이 work_mem 에 다 들어가지 못해 디스크로 쪼개졌다는 뜻이다. 이 경우 인덱스를 만드는 것보다 그 세션의 work_mem 을 올리는 편이 훨씬 효과적이다. 다만 전역 설정을 올리면 위험하다. work_mem 은 커넥션당이 아니라 쿼리 안의 정렬이나 해시 연산 하나당 할당되기 때문이다.

다음 실습에서 할 것

EXPLAIN 과 EXPLAIN ANALYZE 의 차이, BUFFERS 의 효용, loops 의 곱셈, Hash 의 Batches, 그리고 강제로 인덱스를 태웠을 때 오히려 느려지는 경우를 직접 측정해 파일로 남긴다.