금요일에만 발생하던 버그 — 잊고 있던 좀비 인스턴스가 범인이었다
매주 금요일 오후에만 checkout 서비스에서 간헐적으로 500 에러가 발생한 사건의 디버깅 기록입니다. 느린 쿼리, 커넥션 누수, 크론 작업이라는 세 가지 가설이 모두 기각된 끝에, 수개월 전 카나리 배포 실험 후 해체되지 않은 세 번째 인스턴스가 health-check 버그로 DB 커넥션을 고갈시키고 있었다는 것이 밝혀집니다. 주간 단위로 반복되는 패턴 자체가 가장 중요한 단서였다는 교훈을 남기는 사례입니다.
본문
금요일 오후 2시가 지나면 checkout 서비스에서 50건 중 1건꼴로 500 에러가 발생하기 시작하고, 월요일 아침이면 항상 사라져 있었습니다. 에러 메시지는 'sorry, too many clients already'로 PostgreSQL 커넥션 풀 고갈을 가리켰지만, 풀은 20개로 설정되어 있고 평소 금요일 오후에는 6개 정도면 충분했으며 트래픽 급증도 없었습니다. 커넥션을 소비하는 것은 고객이 아니라는 뜻이었습니다.
첫 번째 가설: 느린 쿼리
가장 먼저 의심한 것은 오래 실행되는 쿼리가 커넥션을 붙잡고 있는 시나리오였습니다. 다음 장애 때 pg_stat_activity를 확인했지만 장기 실행 쿼리도, 락도, 블로킹 트랜잭션도 없었습니다. 20개의 커넥션은 전부 active도 idle in transaction도 아닌 완전한 idle 상태였고, 그런데도 Postgres는 21번째 커넥션을 내주기를 거부했습니다. idle이라면 풀이 재사용했어야 하므로 첫 번째 가설은 기각됐습니다.
두 번째 가설: 커넥션 누수
다음 용의자는 애플리케이션에서 커넥션을 열고 풀에 반환하지 않는 전형적인 누수였습니다. 몇 주 전 배포한 리포트 생성 엔드포인트가 ORM 래퍼 밖에서 raw 쿼리를 여럿 실행하고 있어 .release()를 빠뜨리기 좋은 위치였습니다. 코드를 한 줄씩 감사했지만 모든 쿼리가 try/finally로 클라이언트를 반환하고 있었고, pool.connect()와 client.release()마다 로깅을 추가해 스테이징에 배포한 뒤 스크립트로 한 시간 동안 리포트 엔드포인트를 두들겨도 커넥션은 정확히 열리고 닫혔습니다. 두 번째 가설도 기각됐습니다.
세 번째 가설: 스케줄 작업
검색 범위를 넓혀 모든 리포지토리에서 cron, schedule, setInterval을 grep한 결과, 금요일 오후 1시에 실행되는 주간 analytics export가 발견됐습니다. 그러나 이 export는 전용 데이터베이스 유저를 사용했고, pg_stat_activity를 다시 확인하니 20개의 idle 커넥션은 전부 checkout 서비스 유저 소유였습니다. 세 번째 가설도 기각됐습니다.
진짜 원인: 잊혀진 세 번째 인스턴스
계속 지나쳤던 핵심 단서는 커넥션이 idle인데도 Postgres가 재사용하지 못한다는 사실이었습니다. 이것은 누수가 아니라 데이터베이스가 보기엔 idle인 커넥션을 풀이 busy라고 생각하는 상황이었습니다. 서비스는 로드 밸런서 뒤에서 인스턴스 2개를 각각 최대 20개의 풀로 운영 중이었고, 합쳐도 40개로 Postgres 한도 100에 못 미쳤습니다. 그런데 수개월 전 카나리 배포 실험용으로 세운 세 번째 구형 인스턴스를 완전히 해체하지 않은 상태였습니다. 라이브 트래픽을 받지 않아 요청 지표와 에러 대시보드에 나타나지 않았지만 프로세스는 살아 있었고, 시작 시 풀 20개를 전부 열었습니다. 결정타는 health-check pinger의 버그로, 풀의 커넥션을 재사용하는 대신 몇 초마다 새 raw 커넥션을 열고 프로세스 재시작 시에만 정리했습니다. 이 프로세스는 idle 인스턴스를 주간 단위로 재활용하는 auto-scaling 정책 때문에 매주 금요일에 재시작됐고, 누수가 월요일마다 스스로 리셋되면서 주말 이후에는 절대 잡을 수 없고 금요일 오후가 되면 다시 나타나는 패턴이 만들어졌던 것입니다.
해결과 교훈
2주간의 가설 검증 끝에 적용된 수정은 좀비 인스턴스 해체라는 5분짜리 작업이었습니다. 커넥션 수는 금요일 피크 94개에서 안정적인 12개로 떨어졌고 500 에러는 재발하지 않았습니다. 저자가 꼽는 교훈은 세 가지입니다. 첫째, pg_stat_activity를 단순 개수가 아니라 application_name과 usename 기준으로 나눠 봐야 하며, idle이라는 이유로 '우리 것'이라고 가정하지 말고 잊고 있던 서비스까지 포함해 소유자를 확인해야 합니다. 둘째, '이 코드의 무엇이 잘못됐나'가 아니라 '무엇이 함께 돌고 있나'를 물어야 합니다. 세 번째 가설들은 모두 버그가 지금 보고 있는 요청 경로에 있다고 가정했지만 실제로는 수개월간 생각하지 않았던 인프라에 있었습니다. 셋째, 주간 반복 패턴은 헛수고가 아니라 '주간 주기로 도는 무언가'를 외치는 핵심 단서였습니다. 버그는 그 주에 작성한 코드가 아니라 완전히 잊고 있던 서비스에 있었고, 돌이켜보면 진짜 문제는 대개 그런 곳에 숨어 있다고 저자는 마무리합니다.
원문: dev.to / 번역·요약: Trawling