PgBouncer transaction pool로 갈아탄 다음 날 새벽에 벌어진 일

 

session pooling에서 transaction pooling으로 갈아탄 지 이틀째 되던 날 새벽 2시 반, 폰이 울렸다. 결제 API의 P99가 800ms를 넘겼다는 알람. 침대에서 노트북을 여는 순간 이미 뭐가 원인인지 짐작이 갔다. prepared statement 다.

왜 갈아탔나

우리 팀에서 PgBouncer는 오래전부터 session pool로 돌고 있었다. 백엔드가 Django였고, connection이 세션 내내 유지되는 게 편했다. 그런데 최근 서비스가 커지면서 DB 커넥션 수가 감당이 안 됐다. RDS 앞단 PgBouncer에 client는 3천이 넘게 붙는데 server 커넥션은 200~300 정도로 억제하고 싶었다. session pooling에서는 client 한 명이 붙어있는 동안 server 커넥션 하나가 고정으로 잡히니까, 이게 잘 안 됐다.

그래섗 transaction pool로 넘어가기로 했다. 트랜잭션 단위로만 커넥션이 잡히니 재사용이 훨씬 좋다. 커넥션 총량이 절반 이하로 떨어질 거라는 계산도 나왔고, 스테이징에서 며칠 돌려본 결과 문제 없었다.

문제는 스테이징 부하 패턴이 프로덕션과 달랐다는 거다. 이게 뒷통수를 쳤다.

새벽 2시 반의 로그

알람 받고 PgBouncer 로그부터 열어봤다.

LOG S-0x7f8: closing because: prepared statement "S_1" does not exist (age=0s)
LOG S-0x7f9: closing because: prepared statement "S_1" does not exist (age=0s)
LOG S-0x7fa: closing because: prepared statement "S_1" does not exist (age=0s)

같은 라인이 초당 수백 개씩 찍히고 있었다. PgBouncer 1.21 이후로 transaction mode에서도 prepared statement를 지원하긴 하지만, max_prepared_statements 를 0이 아닌 값으로 설정해야 활성화된다. 우리는 이걸 안 켰다. 정확히는, config를 옮기면서 이 옵션이 새로 생긴 건지도 몰랐다.

결과는 뻔했다. 앱이 서버 사이드 prepared statement를 만들면(PREPARE S_1 AS ...), PgBouncer는 이걸 실제 백엔드 커넥션 하나에만 저장한다. 다음 트랜잭션에서 같은 client가 EXECUTE S_1 을 날리면, PgBouncer가 배정하는 백엔드 커넥션은 아까 그 커넥션이 아닐 확률이 훨씬 높다. 그러면 "prepared statement does not exist" 에러가 뜨고 서버 커넥션이 종료된다.

새 커넥션을 다시 여는 비용이 request마다 붙었다. 그래서 레이턴시가 튀었던 거다.

왜 스테이징에서는 안 잡혔나

이게 진짜 짜증나는 부분이었다. 스테이징에서는 이 에러가 로그에 뜨긴 뜨는데 무시할 만한 수준이었다. 이유를 곱씹어봤다.

첫째, 스테이징은 트래픽이 낮아서 client가 몇 명 없다. 그러니까 트랜잭션 사이에 같은 백엔드 커넥션을 다시 받을 확률이 높았다. 확률이 높으니 에러가 잘 안 났다.

둘째, 스테이징 부하 스크립트는 단순한 SELECT 위주였다. Django ORM이 prepared statement로 캐싱하는 쿼리가 별로 많지 않았다. 프로덕션에서 결제 플로우가 도는 쿼리는 파라미터 바인딩된 UPDATE/SELECT 조합이 훨씬 많다.

셋째, 우리 스테이징에는 결제 API 자체가 mock이라, 실제로 이 코드 경로가 안 돌았다. 이건 아예 커버리지 밖이었다.

정리하면, 프로덕션에서 처음 마주친 문제였다. 스테이징에서 검증됐다는 자신감이 무너지는 순간.

두 가지 선택지, 그리고 임시 조치

새벽 3시 즈음에는 두 가지가 남앀 있었다.

하나는 max_prepared_statements 를 켜는 거. PgBouncer가 각 서버 커넥션의 prepared statement 상태를 추적하고, 필요할 때 재작성해준다. 이론적으로 이게 정답이다. 다만 이 값이 커질수록 PgBouncer 메모리 사용량이 늘어난다. 커넥션 수 * statement 수 만큼 트래킹 테이블이 커진다.

다른 하나는 앱 쪽에서 prepared statement 사용을 끄는 거. Django는 DISABLE_SERVER_SIDE_CURSORS 와는 별개로, psycopg2 어댑터 옵션으로 prepare_threshold=None 을 주면 서버 사이드 prepare를 안 만든다. asyncpg 계열은 statement_cache_size=0. 이건 앱 배포가 필요해서 즉시 조치로는 무거웠다.

새벽에 결정한 건 첫 번째였다. max_prepared_statements = 256 을 우선 넣고 PgBouncer를 reload 했다. 위험한 변경이라 하나씩 지켜봤는데, 에러 로그가 사라지고 P99가 200ms대로 돌아왔다. 대신 PgBouncer 프로세스 메모리가 조금씩 오르는 게 보였다. 나중에 512로 올렸고 지금까지는 안정적이다.

며칠 뒤 다시 점검하며

한숨 돌리고 나서 몇 가지가 남았다.

• PgBouncer 버전을 릴리스 노트까지 다 읽고 옮겼어야 했다. 1.21의 prepared statement 지원은 알고는 있었지만, "기본값 0이면 꺼짐" 이라는 디폴트를 놓쳤다. 마이너 업그레이드도 config 옵션의 기본값을 훑는 습관이 필요하다.
• 스테이징 부하 스크립트가 프로덕션 트래픽 shape을 흉내내지 못한다는 사실을 다시 확인했다. 결제 API가 mock인 것도 지금은 어쩔 수 없지만, 최소한 prepared statement 사용률 같은 지표는 스테이징에서도 나와야 했다.
• PgBouncer.SHOW STATS / SHOW POOLS 를 대시보드에 붙여놨다. 서버 재접속 횟수, active/waiting client 수 같은 값이 튀면 알람이 뜨게. 이번에 이게 있었으면 훨씬 빨리 잡았을 거다.

trans pool로 갈아타는 것 자체는 여전히 맞는 결정이었다고 생각한다. 커넥션 총량이 확실히 줄었고, 리소스 여유가 생겼다. 다만 prepared statement 처럼 protocol level에서 상태를 갖는 기능들은, transaction pool 밑에서는 항상 조심해야 한다는 걸 몸으로 다시 배웠다. SET, LISTEN/NOTIFY, advisory lock, cursor 같은 것들도 같은 카테고리다. 이런 것들이 코드베이스에 얼마나 흩어져 있는지, 옮기기 전에 grep 한번 돌려볼 걸 그랬다.

혹시 transaction pool로 넘어갈 계획이 있다면, 앱이 쓰는 protocol level state를 먼저 리스트업하고 시작하시길. 그리고 스테이징에서 안 잡혔다고 안심하지 마시길. 우리 팀이 그거 두 개 다 놓쳐서 새벽에 깼다.