SSE 스트리밍 응답이 20분 걸린 이유를 p95 메트릭으로 추적해본 기록 - 1

SSE 스트리밍이 15~20분 걸린다고 했을 때, 내가 했던 것들 (Prometheus/Grafana 회고)

AI 응답을 SSE로 스트리밍하는 구조를 운영하다 보니 “응답이 너무 오래 걸린다”는 피드백이 들어왔다.
특이한 점은 아예 응답이 없는 게 아니라, 응답은 오는데 전체가 끝나기까지 15~20분이 걸린다는 것.

처음엔 막연히 “네트워크가 느린가?”, “OpenRouter가 밀리나?”, “소켓이 안 닫히나?” 같은 생각부터 들었다.
근데 이건 추측일 뿐이라, 결국 결론은 하나였다.

감으로 추측하지 말고, 숫자로 갈라보자.

---

지금 구조에서 “관측 포인트”를 잡은 위치

내 서비스는 AiProxyService.relayChatStream()에서 OpenRouter의 스트림을 그대로 릴레이한다.

이때 Reactor Flux는 lazy라서, 메트릭을 “메서드 진입 시점”에 찍으면 의미가 없다.
실제로 스트림이 시작되는 건 subscribe 시점이니까 Flux.defer()로 감쌌다.

그리고 doFinally에서 종료를 한 번만 처리하도록 했다.

• 시작 시점: Flux.defer()
• 종료 시점: doFinally

이 구조 덕분에 “요청 하나당 딱 한 번” 측정이 된다. (chunk마다 재는 실수 방지)

---

내가 추가한 메트릭들

내가 궁금했던 건 세 가지였다.

1. 첫 토큰이 늦은가? (연결/큐/레이트리밋/네트워크 계열)
2. 스트림 전체가 긴가? (출력 과다/stop 조건/타임아웃 계열)
3. 스트림이 쌓이는가? (리소스/동시성 문제 계열)

그래서 아래를 넣었다.

• 스트림 전체 duration (openRouterStreamTimer)
• TTFT(Time to first token) (openRouterTtftTimer)
• 활성 스트림 수 gauge (ai_stream_active)
• 종료 사유 카운터 (completed/cancelled/failed)

코드는 대략 이런 형태:

• Timer.Sample total = Timer.start()
• 첫 chunk가 오는 순간 ttft.stop(...)
• 종료 시점에 total.stop(...)
• 종료 signal에 따라 completed/cancelled/failed 카운트 증가

---

Grafana에서 나온 그림이 힌트였다

대시보드에서 먼저 본 건 TTFT였다.

TTFT(p95)가 2~3초 수준이면, “첫 응답은 빨리 오고 있다”는 뜻이다.
여기서 일단 네트워크/연결/큐잉 계열 문제 가능성이 크게 줄었다.

문제는 전체 duration이었다.

전체 스트림 p95가 1200초(=20분) 근처에서 거의 움직이지 않고 수평으로 유지되는 구간이 보였다.
이건 “랜덤하게 느려졌다”기보다는 어떤 규칙에 의해 20분 근처에서 끝나는 스트림이 많다는 신호로 볼 수 있었다.

여기서 내 머릿속 후보는 딱 두 개로 좁혀졌다.

• 모델 출력이 과도하게 길어져서 실제로 15~20분 이상 생성하는 케이스
• 중간 장비/클라이언트/게이트웨이 쪽에 20분 타임아웃(1200s) 이 걸려서 그 시점에 끊기는 케이스

이제 “어디를 봐야 할지”가 구체화되기 시작했다.

---

‘소켓이 늦게 닫히는 문제’가 아닌 이유

처음엔 “소켓이 안 닫히나?”라는 의심도 했다.
근데 내가 재고 있는 건 OS 레벨의 close 완료 시간이 아니라,

Flux가 종료 signal(complete/cancel/error)을 받은 시점까지의 시간이다.

즉,

• “소켓 해제가 20분 걸린다”가 아니라
• “스트림이 20분 동안 유지되다가 종료됐다”에 가깝다.

이 차이를 이해하고 나니, 원인 접근이 완전히 달라졌다.

---

코드 기준으로 다음에 확인해야 할 체크리스트

1) 종료 signal 비율 확인 (complete/cancel/error)

doFinally(sig -> ...)에서 이미 카운터를 올리고 있다.
이걸 Grafana에서 비율로 보면 힌트가 나온다.

• CANCEL이 많다 → 클라이언트/프록시/LB가 중간에 끊는 가능성
• ERROR가 많다 → 네트워크 RST / upstream 에러 가능성
• COMPLETE가 많다 → 모델이 정말로 길게 생성하고 정상 종료하는 가능성

이거 하나만 봐도 “타임아웃 vs 출력 과다”가 많이 갈린다.

2) OpenRouter 요청 파라미터 확인 (max_tokens/stop)

전체 스트림이 길어지는 대표 원인은 보통:

• max_tokens가 너무 큼
• stop 조건이 없거나 동작하지 않음
• 프롬프트가 “계속 출력” 패턴을 유발함

TTFT는 정상인데 duration만 길면 특히 이쪽이 유력해진다.

3) 1200초 타임아웃 존재 여부

p95가 1200초 근처에서 ‘수평’으로 유지되면,
경험상 어딘가에 1200초 타임아웃이 박혀 있는 경우가 많다.

체크 후보:

• Ingress / Nginx proxy_read_timeout
• ALB idle timeout
• Gateway/Netty response timeout
• 클라이언트(프론트/서버) read timeout

---

이번 경험에서 배운 점

이번 케이스에서 제일 크게 느낀 건 이거였다.

“느리다”라는 말은 원인이 아니다.
원인은 “어디가 느리냐”를 분리해서 봐야만 보인다.

TTFT와 total duration을 같이 보면,

• 연결이 느린 문제인지
• 생성이 길어진 문제인지
• 중간에서 끊기는 문제인지

가 훨씬 빠르게 정리된다.

그리고 스트리밍에서는 로그보다 메트릭이 훨씬 먼저다.
(로그로는 20분짜리 요청 하나하나를 사람이 따라가기가 너무 힘들다)

---

다음 액션 (내가 앞으로 하려는 것)

이제 다음은 “원인 확정” 단계다.

• 종료 signal의 비율을 Grafana로 본다 (complete/cancel/error)
• 1200초 타임아웃이 인프라에 있는지 확인한다
• max_tokens/stop을 점검하고, 필요하면 안전장치(상한) 넣는다
• 15분 이상 지속되는 스트림을 “경고”로 잡는 알람을 건다