DOCS/journey/troubleshooting/250723_happybell80_Slack_3초룰.md

Slack 3초 타임아웃 문제 해결

날짜: 2025-07-23
작업자: happybell80 & Claude

오전 12시 00분

Slack 3초 룰 문제 발견

증상:

• Slack이 x-slack-retry-num: 1, x-slack-retry-reason: http_timeout으로 계속 재시도
• 499 에러 발생 (Client Closed Request)
• 같은 메시지 반복 처리로 서버 부하 가중

원인 분석:

• Slack은 3초 내에 200 OK 응답을 받아야 함
• 현재 코드는 RobeingBrain → Gemini API 호출 후 응답
• Gemini 처리에 수초 소요 → 3초 초과

오전 12시 10분

첫 번째 시도: asyncio.create_task() 사용

수정 내용:

# BackgroundTasks 대신 create_task 사용
asyncio.create_task(process_slack_message_with_immediate_response(...))
return JSONResponse({"status": "ok"})

문제점:

• FastAPI가 create_task()로 만든 태스크도 기다릴 수 있음
• 실제로는 응답이 지연됨

오전 12시 20분

Dockerfile 문제 발견

배경:

• Gemini CLI 실행 시 npm 홈 디렉토리 접근 실패
• EACCES: permission denied, mkdir '/home/appuser'

원인:

# 문제: -m 옵션 없이 유저 생성
RUN groupadd -r appuser && useradd -r -g appuser appuser

해결:

# 홈 디렉토리 생성하도록 수정
RUN groupadd -r appuser && useradd -r -g appuser -m -d /home/appuser appuser

오전 12시 30분

시간 측정 코드 추가

목적: 실제 응답 시간 측정

결과:

• 함수 내부: 27.8ms에 return
• 하지만 Slack은 여전히 http_timeout으로 재시도
• 실제로는 응답이 나가지 않음

오전 12시 40분

진짜 문제 발견: subprocess.run() 블로킹

핵심 문제:

# gemini_service.py의 동기 호출
result = subprocess.run(cmd, capture_output=True, text=True, check=True, timeout=15)

문제점:

• subprocess.run()은 동기 호출
• 15초간 전체 이벤트 루프 블로킹
• create_task()를 써도 소용없음
• FastAPI는 27ms에 return했지만, 같은 코루틴에서 Gemini CLI 호출이 끝날 때까지 대기

오전 12시 50분

해결책: asyncio.create_subprocess_exec() 사용

수정 내용:

# 비동기 subprocess로 변경
proc = await asyncio.create_subprocess_exec(
    *cmd,
    stdout=asyncio.subprocess.PIPE,
    stderr=asyncio.subprocess.PIPE
)

try:
    stdout, stderr = await asyncio.wait_for(
        proc.communicate(), 
        timeout=self.cli_timeout
    )
except asyncio.TimeoutError:
    proc.kill()
    await proc.wait()
    return "죄송합니다. 응답이 지연되고 있습니다..."

교훈

1. 3초 룰은 단순히 빨리 return하는 것이 아님

• 이벤트 루프가 블로킹되면 응답이 나가지 않음
• subprocess.run() 같은 동기 호출은 치명적

2. asyncio.create_task() vs BackgroundTasks

• create_task(): Python 기본, FastAPI가 추적 안 함
• BackgroundTasks: FastAPI가 관리, 응답 후 실행 보장

3. 디버깅 시 시간 측정 중요

• 로그상 빠른 응답이라도 실제 네트워크 응답과 다를 수 있음
• Slack의 재시도 헤더가 진실을 말해줌

4. 비동기 프로그래밍의 함정

• 하나의 동기 호출이 전체 성능을 망칠 수 있음
• 특히 외부 프로세스 호출 시 주의 필요

다음 단계

1. gemini_service.py의 모든 _call_gemini_cli 호출을 await로 변경
2. BackgroundTasks로 복원 고려
3. 배포 후 실제 3초 내 응답 확인