docs: 250723 트러블슈팅 - Slack 3초 타임아웃 해결 및 스킬 호출 문제

- Slack 3초 타임아웃 완전 해결 (asyncio import 추가)
- 메시지 중복 처리 문제 해결 (DM/멘션 구분)
- 이메일 스킬 호출 안되는 문제 발견 및 분석

🤖 Generated with [Claude Code](https://claude.ai/code)

Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
happybell80 2025-07-23 01:16:06 +09:00
parent aea7632e6c
commit 4a71eddb43
2 changed files with 216 additions and 0 deletions

View File

@ -0,0 +1,127 @@
# 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() 사용
**수정 내용**:
```python
# 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'`
**원인**:
```dockerfile
# 문제: -m 옵션 없이 유저 생성
RUN groupadd -r appuser && useradd -r -g appuser appuser
```
**해결**:
```dockerfile
# 홈 디렉토리 생성하도록 수정
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() 블로킹
**핵심 문제**:
```python
# 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() 사용
**수정 내용**:
```python
# 비동기 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초 내 응답 확인

View File

@ -0,0 +1,89 @@
# Slack 3초 타임아웃 해결 및 스킬 호출 문제
**날짜**: 2025-07-23
**작업자**: happybell80 & Claude
## 오전 1시 00분
### Slack 3초 타임아웃 문제 완전 해결
**배경**:
- 이전에 subprocess.run()을 asyncio.create_subprocess_exec()로 변경했으나
- asyncio import 누락으로 실패
**해결**:
```python
# gemini_service.py에 asyncio import 추가
import asyncio
```
**결과**:
- Slack 재시도 없음 (RETRY, timeout 관련 로그 0건)
- 응답 시간: 1.8ms ~ 4.8ms로 즉시 200 OK 반환
- Gemini 처리: 5~6초 소요 (비동기로 정상 작동)
### Slack 메시지 중복 처리 문제 해결
**문제**:
- 하나의 메시지가 message와 app_mention 두 번 처리
- 결과적으로 같은 답변 2번 전송
**원인**:
- Slack에서 멘션(@로빙)이 포함된 메시지는 두 이벤트 모두 발생
**해결**:
```python
# app_mention이거나 DM인 message만 처리
is_dm = event.get("channel_type") == "im"
if event_type == "app_mention" or (event_type == "message" and is_dm):
# 처리 로직
```
**결과**:
- DM: message 이벤트로 처리
- 채널 멘션: app_mention 이벤트로만 처리
- 중복 응답 방지 완료
## 오전 1시 10분
### 이메일 스킬 호출 문제 발견
**증상**:
- 사용자: "메일 확인해줘"
- Gemini: "로빙은 이메일 서비스를 통해 메일을 확인할 수 있습니다..."
- 실제 email_skill 호출 없음
**로그 분석**:
```
16:08:06 - builtin_skills 2개 설치됨
16:09:43 - Gemini 응답: "메일 확인하겠다"
16:12:03 - Gemini 응답: "읽지 않은 메일 확인하겠다"
```
- email_skill 관련 로그 전무
- skill 호출 로그 없음
**문제점 정리**:
1. **스킬 미설치**: email_skill이 builtin_skills에 포함되지 않음
2. **Gemini만 답변**: 실제 스킬 호출 없이 텍스트 답변만 생성
3. **스킬 라우팅 실패**: RobeingBrain이 스킬로 라우팅하지 않음
**예상 원인**:
- email_skill이 builtin_skills에 등록되지 않음
- 또는 스킬 매칭 로직이 작동하지 않음
- Gemini가 단순 텍스트 응답만 생성
## 교훈
1. **비동기 처리 시 import 확인 필수**
- asyncio 등 필요한 모듈 import 누락 주의
- 특히 동기→비동기 변환 시 체크
2. **Slack 이벤트 중복 처리 주의**
- 멘션이 있는 메시지는 두 가지 이벤트 발생
- channel_type으로 DM 구분 필요
3. **스킬 시스템 통합 테스트 필요**
- 스킬이 실제로 호출되는지 확인
- Gemini 응답과 스킬 실행이 연동되는지 검증
- 내일 email_skill 설치 및 라우팅 문제 해결 예정