Incident Library

IL-0330 incident.io · 2023-04-20 (게시일)database

Go database/sql 커넥션 풀을 기다리던 요청이 2주 동안 간헐적으로 타임아웃됐고, 한 요청은 거의 20초를 기다렸다

2023년 초 incident.io 애플리케이션은 2주 동안 데이터베이스를 쓸 때 간헐적으로 타임아웃을 겪었다. 첫 신호는 고객 신고와 Sentry 의 context canceled 오류였다. 트레이스를 보니 요청이 Go 의 database/sql 패키지가 관리하는 클라이언트 쪽 커넥션 풀에서 커넥션을 얻으려고 거의 20초를 기다렸다. 이 패키지는 커넥션 풀로 한 번에 데이터베이스와 통신하는 앱 프로세스 수를 제한한다. 쓸 수 있는 커넥션이 다 쓰이고 있으면 작업이 커넥션을 얻을 때까지 막힌다. 팀은 go.patch 파일로 database/sql 을 고쳐 ConnectionPoolWait 에 트레이스를 넣어 두었기 때문에 이 대기를 볼 수 있었다. 대기는 특정 풀 하나가 아니라 여러 곳에 퍼져 있었다. 트래픽, PubSub 지표, Heroku 의 Postgres 통계도 평소와 같았다.

뚜렷한 출발점이 없어 팀은 느려 보이는 쿼리를 빠르게 고쳤다. 정책 위반 계산을 머티리얼라이즈드 뷰로 옮기고, 인덱스를 더하고, 인덱스 없는 열로 거르는 조인 쿼리를 다시 썼다. 며칠 안에 타임아웃이 다시 나자 모든 트랜잭션에 1초 락 타임아웃을 걸었다. 또 Slack 웹훅을 받으면 데이터베이스 쿼리 없이 바로 PubSub 로 넘기도록 바꿨다. 다음 날 또 타임아웃이 나자 팀은 관측성을 키우는 데 집중했다. ngrok/sqlmw 패키지로 미들웨어를 만들고, trackUsage 메서드로 작업마다 데이터베이스 커넥션을 쥐고 있던 시간을 세어 로그와 트레이스에 남겼다. gorm 의 훅은 커넥션 풀 대기 시간까지 포함해 재기 때문에 쓰지 않았다. 2주 동안 성능과 관측성을 겨냥한 변경 24개를 배포했다.

로그를 살피던 중 팀은 Slack 모달 제출을 처리할 때마다 필요 없는 트랜잭션을 열고 있다는 것을 발견했다. 이 HTTP 엔드포인트는 사용자가 /inc 같은 슬래시 명령의 화면에서 확인 버튼을 누를 때마다 Slack 이 호출한다. 대부분의 모달 제출에서 트랜잭션을 없애고, 트랜잭션 보장이 필요한 코드 경로에만 명시적으로 넣었다. 타임아웃이 매일 나지는 않아서 이것이 근본 원인이었다는 것은 며칠 뒤에야 확인됐다. 느린 것 하나가 아니라 짧은 트랜잭션 여러 개가 쌓여 문제를 만들었다. 글을 쓴 시점까지 4개월 동안 데이터베이스 타임아웃은 없었다.

심각도
–
영향 범위
Intermittent timeouts on API requests and other operations that used the database, over a period of two weeks
영향 사용자
–
지역
–
감지까지
–
복구까지
–

증상

2023년 초 incident.io 애플리케이션이 데이터베이스를 쓰는 동안 간헐적으로 타임아웃이 났다. 고객 신고가 들어왔고, 오류 수집 도구 Sentry 에 context canceled 오류가 한꺼번에 쏟아졌다.

Grafana 의 API 대시보드에서는 일부 API 요청이 타임아웃된 것이 보였지만 1분이 안 돼 정상으로 돌아왔다. 실패한 요청 하나의 트레이스를 열어 보니 HTTP 요청이 커넥션 풀에서 쓸 수 있는 커넥션을 얻으려고 거의 20초를 기다렸다. 이 대기는 database.sql.ConnectionPoolWait 스팬에 나타났다.

Kibana 에서 커넥션을 기다린 요청의 종류를 나눠 보니 특정 커넥션 풀 하나가 아니라 여러 곳에 퍼져 있었다. 이전 HTTP 트래픽과 PubSub 지표에는 평소와 다른 점이 없었다. Heroku 의 Postgres 통계에서도 데이터베이스 부하는 평범한 수준이었다. 데이터베이스 사용을 크게 바꾼 코드 변경도, 갑작스러운 트래픽 변화도 없었다. 로그, 트레이스, 대시보드에도 눈에 띄는 것이 없었다.

팀은 느려 보이고 빨리 고칠 수 있는 쿼리부터 손봤고 장애를 닫았다. 하지만 며칠 안에 다시 커넥션 풀 대기로 타임아웃이 났다. Kibana 와 Google Cloud Trace 에서 느린 요청 사이에 뚜렷한 규칙은 보이지 않았다. 모든 트랜잭션에 1초 락 타임아웃을 걸어 봤지만 아무것도 깨지지 않았고 원인에 가까워지지도 않았다. Slack 이벤트를 비동기로 처리하게 바꾼 다음 날에도 타임아웃이 또 났다.

증상 커넥션 풀 고갈간헐적 타임아웃

원인

원인 소프트웨어 결함

구성 요소 데이터베이스
기여 요인 모니터링 사각지대
촉발
–

감지

고객 신고가 들어왔고 Sentry 에 context canceled 오류가 쏟아지면서 알아챘다. 온콜 엔지니어가 장애를 열고 Grafana 의 API 대시보드에서 타임아웃을 확인했다. 두 번째 타임아웃 때는 장애가 자동으로 열리고 온콜 엔지니어가 호출됐다.

조치

후속 조치

–

교훈

한 번에 모든 것이 풀리는 결정적인 발견은 없었다. 대신 그 과정에서 이런 문제를 진단할 준비가 훨씬 잘 됐고, 실제 성능 개선도 함께 이뤄졌다. 원인은 눈에 띄게 느린 것 하나가 아니라 짧은 트랜잭션 여러 개가 합쳐진 것이었다. 애플리케이션의 부분마다 다른 데이터베이스를 썼다면 아마 더 빨리 찾았을 것이다. 하지만 그러면 분산 트랜잭션을 고민해야 하고 개발 환경도 덜 편해지므로, 팀은 지금의 선택을 유지한다.

출처

관련 사례

내 클러스터에도 있는지 확인하기

kubegap 은 Claude Code 나 Codex 에서 쿠버네티스 클러스터를 읽기만 하며 이 사례와 같은 상태를 점검합니다. 이 사례의 구성 요소: 데이터베이스. 점검 항목의 근거는 이 사례 같은 공개 보고서입니다.

kubegap 열기

AI 도구와 스크립트용

API 는 키가 필요 없습니다. MCP 서버는 search_incidents, get_incident, list_incidents, get_topic, vocab 도구를 내놓습니다. 사용법은 API 와 MCP.