DB pool timeout을 pool size가 아니라 lifecycle 문제로 보기

Sentry에 SQLAlchemy QueuePool timeout이 P1으로 올라왔을 때 가장 쉬운 해결은 pool size를 키우는 것이었다. 하지만 route와 timestamp를 묶어보니 문제는 DB capacity 하나로 설명되지 않았다. 첫 번째 병목은 외부 I/O 동안 너무 오래 살아 있는 DB session이었고, 후속으로 남은 timeout은 detail 요청을 한꺼번에 fan-out하면서 같은 pool을 압박한 케이스였다.

요약

• 문제: detail 조회 요청과 SSE stream이 같은 시각에 QueuePool timeout을 맞았다.
• 첫 판단: pool size를 키우기 전에 connection을 오래 잡는 session lifecycle을 확인했다.
• 후속 판단: session release 이후에도 남은 timeout은 detail prefetch fan-out이 stream polling과 겹친 문제였다.
• 해결: 외부 I/O 구간에서는 session을 닫고, detail 요청은 bounded concurrency로 제한했다.
• 배운 점: pool timeout은 "DB가 작다"보다 "오래 잡고 있거나, 동시에 너무 많이 빌리고 있다"는 신호일 수 있다.

상황

Place2Page에는 생성 결과를 비교하고 세부 기록을 보는 화면이 있다. 프롬프트 실험을 여러 개 돌리던 시점에 Sentry에는 다음 계열 이슈가 묶여 올라왔다.

TimeoutError: QueuePool limit of size 5 overflow 10 reached,
connection timed out, timeout 30.00

영향을 받은 route 계열은 두 종류였다.

detail endpoint
generation stream endpoint

전자는 생성 세부 기록을 보는 endpoint이고, 후자는 생성 진행상황을 보내는 SSE endpoint다. 관리성 화면에서 시작된 문제처럼 보여도 가볍게 볼 수 없었다. 같은 pool을 말리면 실제 generation stream에도 영향을 줄 수 있기 때문이다.

왜 pool size부터 키우지 않았나

Connection pool은 DB connection을 매 요청마다 새로 만들지 않기 위해 재사용하는 장치다. pool timeout은 동시에 빌릴 수 있는 connection이 모두 나갔고, 정해진 시간 안에 반납되지 않았다는 뜻이다.

그래서 숫자만 키우면 당장은 조용해질 수 있다. 하지만 connection을 너무 오래 들고 있거나 한 화면이 한꺼번에 너무 많은 DB-backed 요청을 날리는 구조라면 pool size 조정은 증상을 늦추는 일에 가깝다.

SQLAlchemy error guide도 이 오류를 pool의 보호 장치로 설명한다. FastAPI의 yield dependency도 같이 봤다. request-scoped dependency cleanup은 response lifecycle 뒤에 실행되는데 StreamingResponse는 응답이 오래 열려 있을 수 있다.

당시 로컬 FastAPI Depends signature에는 최신 문서에서 보이는 scope="function" 옵션이 없었다.

Depends(dependency=None, *, use_cache=True)

그래서 dependency 옵션에 기대지 않고, 안전한 경계에서 session.close()를 명시적으로 호출하는 방향으로 잡았다.

증거 1: StreamingResponse가 session을 오래 잡았다

기존 SSE route는 stream 시작 전에 권한 확인을 했다.

ensure_access(session, project_id, user)

return StreamingResponse(event_generator(), media_type="text/event-stream")

문제는 session이 request-scoped dependency에서 왔다는 점이다. StreamingResponse를 반환했다고 바로 닫히지는 않는다.

이걸 테스트로 먼저 고정했다.

def test_stream_generation_releases_access_session_before_streaming(monkeypatch):
    session = Mock()
    request = Mock()
    user = SimpleNamespace(id="user-1", is_admin=False)
    ensure_access = Mock()
    monkeypatch.setattr(projects, "ensure_access", ensure_access)

    response = asyncio.run(projects.stream_generation("proj-1", request, session, user))

    ensure_access.assert_called_once_with(session, "proj-1", user)
    session.close.assert_called_once()
    assert response.media_type == "text/event-stream"

처음에는 session.close()가 호출되지 않아 실패했다. 수정 후에는 access check 직후 session을 닫았다. stream 안에서 DB가 필요할 때는 이미 별도의 짧은 SessionLocal() context를 쓰고 있었기 때문이다.

증거 2: AI generation이 DB session 안에 있었다

run_generation()도 비슷했다. 처음 구조는 생성 전체를 하나의 DB session context 안에서 실행했다.

with SessionLocal() as session:
  project 조회
  prompt/runtime 설정 조회
  place data fetch
  AI HTML generation
  landing/debug log 저장

place data fetch와 AI HTML generation은 DB 작업이 아니라 외부 I/O다. 이 시간 동안 session이 살아 있으면 connection을 계속 점유할 수 있다.

그래서 외부 fetch와 AI generation에 들어가기 전에 session이 닫혀 있어야 한다는 테스트를 만들었다. 이 테스트도 처음에는 실패했고, 수정 후에는 DB 작업 구간과 외부 I/O 구간이 분리됐다.

최종 구조는 이렇게 바뀌었다.

DB setup window
  read project/runtime/profile
  close session

external window
  fetch place data

DB persist window
  save place snapshot
  close session

external window
  AI generation

DB persist window
  save landing/debug log
  close session

코드는 조금 길어졌다. 대신 connection을 점유하는 구간이 실제 DB 작업으로 좁아졌다.

증거 3: 남은 timeout은 fan-out이었다

처음 fix 뒤에도 같은 계열의 Sentry 이슈가 일부 남아 있었다. 다시 보니 stream endpoint의 session release guard는 이미 들어가 있었고, 기존 유저 write도 과도하게 반복되지 않도록 제한되어 있었다.

남은 증거는 detail preview prefetch였다. 특정 탭이 열릴 때 현재 페이지의 detail record를 최대 50개까지 동시에 가져오고 있었다. 각 요청은 권한 확인을 위한 DB lookup과 detail query를 실행한다. 이 fan-out이 stream polling read와 같은 시간대에 겹쳤다.

Sentry log를 공개 가능한 형태로 패턴화하면 이런 모양이었다.

18:08:35  GET detail endpoint            200     30096ms
18:08:35  GET detail endpoint            200     30097ms
18:08:35  GET detail endpoint            200     30451ms
18:08:35  GET detail endpoint            failed  TimeoutError
18:08:35  GET generation stream endpoint failed  TimeoutError

단일 slow query였다면 특정 endpoint 하나가 길게 찍혔을 가능성이 높다. 여기서는 같은 화면에서 생긴 detail request 묶음이 pool timeout 값인 30초 주변에 한꺼번에 완료되거나 실패했다. 그래서 frontend detail prefetch를 bounded worker 방식으로 바꾸고, 동시 요청 수를 제한했다.

검증

처음 만든 RED 테스트 두 개는 수정 후 GREEN이 됐다.

test_stream_generation_releases_access_session_before_streaming
test_run_generation_releases_db_session_around_external_generation_calls

관련 범위도 같이 돌렸다.

cd apps/api
uv run pytest -q <generation service, detail route, project route, stream state tests>

결과는 183 passed, 1 warning이었다. 관련 router와 test 파일에 대한 ruff check도 통과했다.

후속 fan-out fix는 detail prefetch가 지정된 concurrency를 넘지 않는지 테스트로 고정했다.

이 검증에서 중요한 점은 "pool timeout이 완전히 사라졌다"는 식으로 과장하지 않는 것이다. 확인한 것은 session release boundary와 fan-out limit이 의도대로 작동한다는 점이다.

다음에는 이렇게 판단한다

• pool timeout을 보면 pool size부터 키우지 않는다. 먼저 connection을 오래 잡는 lifecycle과 동시에 몰리는 fan-out을 분리해서 본다.
• Sentry에서 같은 초에 30초대 요청이 여러 개 몰려 있으면 slow query보다 concurrency 문제를 먼저 의심한다.
• StreamingResponse, background task, AI/provider 호출, 외부 fetch는 DB session 수명을 별도로 확인한다.
• 관리성 화면이라도 DB-backed detail endpoint를 과하게 prefetch하면 DB pool을 압박할 수 있다고 본다.
• lifecycle을 줄이고 fan-out을 제한한 뒤에도 정상 트래픽에서 부족하면 그때 pool size, worker 수, DB max connection을 조정한다.

참고

• SQLAlchemy 2.0 Errors: QueuePool limit of size x overflow y reached
• FastAPI: Dependencies with yield