pg_stat_statements로 서버를 가장 많이 잡아먹는 쿼리 찾기

한서윤 · 2026년 10월 30일 · 운영과 도구

DB 서버 CPU가 평일 낮마다 70%를 넘기던 시기가 있었다. 장애가 난 건 아니었지만 여유도 없었다. 트래픽이 조금만 몰려도 응답 시간 그래프가 같이 출렁였다. 무엇이 서버를 갉아먹는지 알고 싶어서 pg_stat_statements를 켰다. 그리고 첫날 엉뚱한 쿼리를 고쳤다.

이 확장은 서버에서 실행된 쿼리를 모양별로 묶어 호출 수, 누적 실행 시간, 읽은 블록 수를 쌓아 둔다. 숫자 자체는 정직하다. 그런데 어느 열로 정렬하느냐에 따라 전혀 다른 이야기를 들려준다. 그날 이후로 굳어진, 이 뷰를 읽는 순서와 내가 몇 번 속았던 지점을 적어 둔다.

켜기 전에 확인할 것

pg_stat_statements는 공유 메모리를 쓰기 때문에 shared_preload_libraries에 올려야 하고, 그러려면 서버를 재시작해야 한다. 운영 DB라면 이 재시작 한 번 때문에 작업 일정을 따로 잡아야 한다. 재시작한 뒤에는 통계를 볼 데이터베이스에서 확장을 만든다.

-- postgresql.conf
-- shared_preload_libraries = 'pg_stat_statements'
-- compute_query_id = auto

CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

compute_query_id는 기본값이 auto라서 확장을 올리면 쿼리 ID가 알아서 계산된다. 버전 차이도 하나 기억해 둔다. PostgreSQL 12 이하에서는 열 이름이 total_time, mean_time이고, 13부터 total_exec_time, mean_exec_time으로 바뀌었다. 계획 시간을 따로 재는 track_planning은 기본으로 꺼져 있다. 인터넷에서 복사한 쿼리가 열이 없다며 실패하면 대개 버전이 안 맞는 경우다.

평균으로 정렬했다가 헛수고한 날

처음 이 뷰를 열었을 때 나는 별생각 없이 mean_exec_time DESC로 정렬했다. 맨 위에 평균 3초가 넘는 월간 정산 리포트 쿼리가 올라왔다. 누가 봐도 범인 같았다. 반나절 동안 인덱스를 붙이고 조인 순서를 바꿔 300ms까지 줄였다. 배포하고 CPU 그래프를 열었는데 선이 그대로였다. 허탈했다.

그래서 이번에는 총 실행 시간으로 다시 정렬했다. 그때 본 숫자를 반올림하면 대략 이랬다.

내가 고친 리포트 쿼리는 2.5%였다. 1ms도 안 걸리는 세션 조회가 서버 시간의 절반을 쓰고 있었다. 요청마다 미들웨어가 세션을 한 번, 권한 검사 코드가 또 한 번 읽고 있었다.

서버가 쓴 시간은 호출 수와 평균의 곱이다

total_exec_time은 호출 수에 평균 시간을 곱한 값과 같다. 호출 수를 가로, 평균을 세로로 두고 사각형을 그리면 서버가 실제로 쓴 시간은 그 넓이다. 평균 정렬은 높이만 보고, 총 시간 정렬은 넓이를 본다.

지금은 이 쿼리를 가장 먼저 돌린다. 전체 대비 비중을 같이 뽑으면 위쪽 몇 줄이 서버 시간의 대부분을 차지한다는 게 바로 보인다.

SELECT queryid,
       calls,
       round(total_exec_time::numeric, 1) AS total_ms,
       round(mean_exec_time::numeric, 2)  AS mean_ms,
       round((100 * total_exec_time / sum(total_exec_time) OVER ())::numeric, 1) AS pct,
       left(query, 60) AS query
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;

넓고 납작한 사각형은 쿼리보다 애플리케이션 쪽을 의심할 차례라는 신호다. 반복문 안의 쿼리, ORM의 N+1, 너무 자주 도는 폴링 같은 것들이다. 세션 조회는 인덱스를 손댈 게 아니었다. 요청 하나에서 한 번만 읽도록 결과를 넘겨주니 호출 수가 절반 아래로 떨어졌고, CPU 선도 그제야 내려왔다. 평균 정렬이 쓸모없다는 말은 아니다. 사용자가 느끼는 한 번의 느림을 찾을 때는 평균과 max_exec_time이 맞는 지표다. 다만 서버가 버거워할 때 먼저 볼 열은 아니다.

shared_blks_read 비율로 디스크 쪽을 본다

시간 다음으로 보는 건 블록이다. shared_blks_hit은 공유 버퍼에서 바로 찾은 블록 수이고, shared_blks_read는 버퍼에 없어서 밖에서 가져온 블록 수다. 둘을 더한 값 가운데 read가 차지하는 비율을 보면 어느 쿼리가 캐시를 비켜 가는지 드러난다.

SELECT queryid,
       calls,
       shared_blks_hit,
       shared_blks_read,
       round(100.0 * shared_blks_read
             / nullif(shared_blks_hit + shared_blks_read, 0), 1) AS read_pct,
       left(query, 60) AS query
FROM pg_stat_statements
ORDER BY shared_blks_read DESC
LIMIT 10;

이 숫자를 처음 볼 때 착각한 게 있다. read가 곧 디스크 I/O라고 생각했다. 사실 PostgreSQL은 OS 페이지 캐시에서 온 블록과 진짜 디스크에서 온 블록을 구분하지 못한다. 둘 다 read로 센다. 그래서 read 비율이 높아도 디스크 그래프는 조용할 수 있다. 그렇다고 무시할 숫자는 아니다. 한 쿼리가 버퍼로 블록을 끌어올 때마다 다른 쿼리가 쓰던 블록이 밀려나기 때문이다. 나는 read 절대량이 큰 쿼리를 먼저 보고, 비율은 그 쿼리가 원래 넓게 훑는 종류인지 판단하는 데 쓴다.

누적 통계는 언제부터 쌓인 숫자인가

리포트 쿼리를 고치고 한 달쯤 지나 다시 뷰를 열었다. 고친 그 쿼리가 여전히 평균 상위에 있었다. 순간 배포가 빠졌나 싶어 당황했다. 알고 보니 통계는 확장을 켠 날부터 계속 쌓이고 있었고, 고치기 전 3초짜리 실행들이 평균을 붙잡고 있었다. 기본 설정이 pg_stat_statements.save = on이라 재시작해도 숫자는 사라지지 않는다.

그래서 숫자를 읽기 전에 그 숫자가 언제부터의 것인지 먼저 확인한다.

SELECT dealloc, stats_reset FROM pg_stat_statements_info;

stats_reset은 마지막으로 전체를 리셋한 시각이다. PostgreSQL 17부터는 뷰에 stats_since 열이 생겨 쿼리마다 통계를 쌓기 시작한 시각을 볼 수 있다. dealloc도 꼭 본다. 추적하는 쿼리 수는 pg_stat_statements.max(기본 5000)까지인데, 이 한도를 넘기면 자주 안 쓰이는 항목부터 버려지고 그때마다 dealloc이 올라간다. 이 값이 계속 오른다면 상위 목록도 완전하다고 믿기 어렵다.

리셋은 SELECT pg_stat_statements_reset(); 한 줄이면 되지만, 다른 사람이 보던 숫자까지 날아간다. 그래서 요즘은 리셋 대신 스냅샷을 떠 두고 차이를 본다.

CREATE TABLE pgss_snap AS
SELECT now() AS taken_at, queryid, dbid, userid, calls, total_exec_time
FROM pg_stat_statements;

-- 한두 시간 뒤
SELECT s.queryid,
       s.calls - p.calls AS calls,
       round((s.total_exec_time - p.total_exec_time)::numeric, 1) AS total_ms,
       left(s.query, 60) AS query
FROM pg_stat_statements s
JOIN pgss_snap p USING (queryid, dbid, userid)
ORDER BY total_ms DESC
LIMIT 10;

배포 전후나 피크 시간대만 잘라 볼 수 있어서 누적값보다 판단이 훨씬 쉬워졌다.

정규화가 만드는 착시

pg_stat_statements는 상수를 $1 같은 기호로 바꿔서 모양이 같은 쿼리를 한 줄로 묶는다. 덕분에 목록이 읽을 만한 길이가 되지만, 값에 따라 실행 비용이 크게 다른 쿼리는 평균이 아무것도 대변하지 못하게 된다.

거래처별 주문을 뽑는 WHERE tenant_id = $1 쿼리가 평균 8ms로 얌전하게 찍혀 있던 적이 있다. 그런데 가장 큰 거래처 담당자만 화면이 느리다고 했다. 그 거래처는 주문이 다른 곳의 수백 배였다. 수많은 작은 거래처의 빠른 실행이 평균을 깎아 주고 있었던 것이다. 그 뒤로는 평균 옆에 max_exec_time과 stddev_exec_time을 같이 놓고, 둘의 차이가 크면 값별로 따로 재 본다.

반대로 하나여야 할 쿼리가 여러 줄로 갈라지기도 한다.

• PostgreSQL 17까지는 IN 목록의 길이가 다르면 다른 쿼리로 묶였다. 18부터는 IN ($1 /*, ... */) 꼴로 합쳐진다.
• 텍스트가 같아도 search_path가 달라 의미가 바뀌면 다른 항목이 된다.
• 테이블 별칭만 달라도 queryid가 갈린다.

ORM이 ID 목록을 IN으로 넘기는 화면이라면 17 이하에서는 같은 쿼리가 수십 줄로 흩어져, 하나하나는 순위 밖에 머물면서 합치면 1위인 일이 생긴다. 상위 목록에 비슷한 쿼리가 여러 줄 보이면 left(query, 40)처럼 앞부분으로 한 번 묶어서 다시 더해 본다.

지금 이 뷰를 읽는 순서

요즘은 pg_stat_statements를 열면 순서가 정해져 있다. pg_stat_statements_info로 언제부터 쌓인 숫자인지 확인하고, 총 시간 비중으로 위쪽 다섯 줄을 본다. 그다음 각 줄이 넓고 납작한지 좁고 높은지 따진다. 넓으면 애플리케이션 코드부터 열고, 높으면 실행 계획을 본다. 블록 read와 max 값은 그 판단을 거들 때만 꺼낸다.

돌아보면 평균으로 정렬하던 시절의 나는 느린 쿼리를 찾고 있었고, 서버는 많이 도는 쿼리 때문에 힘들어하고 있었다. 둘은 같은 질문이 아니다. 지금은 숫자를 보기 전에 이번에 무엇을 묻고 싶은지부터 정하고, 그 질문에 맞는 열로 정렬한다.