Reduce: Document to 72 lines with core facts - OOM Kill, error logging, schedule changes
This commit is contained in:
happybell80
parent
c62a1b9b27
commit
1fa7b2186b
@ -1,213 +1,73 @@
|
||||
# CompanyX 헤드라인 실패: 리소스 경합 및 빈 에러 메시지 문제
|
||||
# CompanyX 헤드라인 실패: 리소스 경합 및 OOM Kill
|
||||
|
||||
**작성일**: 2025-09-08
|
||||
**작성자**: happybell80
|
||||
**상태**: 원인 파악 완료, 해결 방안 제시
|
||||
|
||||
---
|
||||
**작성일**: 2025-09-08
|
||||
**작성자**: happybell80
|
||||
**상태**: 원인 파악, 일부 해결
|
||||
|
||||
## 문제 요약
|
||||
|
||||
매일 09:00에 실행되는 CompanyX 헤드라인 포스팅이 간헐적으로 실패하며, rb8001 로그에 "fetch_naver_headlines error: " 뒤에 에러 메시지가 비어있는 현상 발생.
|
||||
매일 09:00 CompanyX 헤드라인 실패, rb8001 로그에 빈 에러 메시지
|
||||
|
||||
## 증상
|
||||
- rb8001 로그: "fetch_naver_headlines error: " (빈 메시지)
|
||||
- 실패 빈도: 30-40%
|
||||
- skill-news API 직접 테스트: 정상 (4-7초 소요)
|
||||
|
||||
1. **로그 현상**
|
||||
- rb8001 로그: "fetch_naver_headlines error: " (에러 메시지 비어있음)
|
||||
- 실패 시점: 매일 09:00:00 전후
|
||||
- 발생 빈도: 간헐적 (약 30-40% 확률)
|
||||
## 원인
|
||||
|
||||
2. **동작 확인**
|
||||
- skill-news API 직접 테스트: 정상 (22개 기사 반환)
|
||||
- 응답 시간: 평균 4-7초 (Playwright 브라우저 실행 포함)
|
||||
- 네트워크 연결: 정상 (rb8001 → localhost:8505)
|
||||
|
||||
## 근본 원인 분석
|
||||
|
||||
### 1. 리소스 경합 문제
|
||||
|
||||
**09:00 동시 실행 서비스들**:
|
||||
### 1. 리소스 경합
|
||||
```
|
||||
09:00:00 - 일일 브리핑 (rb8001 → skill-email)
|
||||
09:00:00 - CompanyX 헤드라인 (rb8001 → skill-news)
|
||||
09:00:00 - 일일 브리핑 (skill-email)
|
||||
09:00:00 - 헤드라인 (skill-news + Playwright)
|
||||
```
|
||||
동시 실행으로 메모리/CPU 피크
|
||||
|
||||
**리소스 사용 패턴**:
|
||||
- skill-email: Gmail API 호출, 이메일 처리
|
||||
- skill-news: Playwright 브라우저 실행, 네이버 블로그 스크래핑
|
||||
- 동시 실행 시 메모리/CPU 피크 발생
|
||||
|
||||
### 2. 빈 에러 메시지 원인
|
||||
|
||||
**Python/aiohttp의 특정 예외 동작**:
|
||||
### 2. 빈 에러 메시지
|
||||
```python
|
||||
# rb8001/app/commands/skill_commands.py:241-243
|
||||
except Exception as e:
|
||||
logger.error(f"fetch_naver_headlines error: {e}") # str(e)가 빈 문자열
|
||||
return {"success": False, "message": str(e)}
|
||||
logger.error(f"error: {e}") # MemoryError는 str(e)=""
|
||||
```
|
||||
MemoryError, InvalidURL 등은 str() 시 빈 문자열 반환
|
||||
|
||||
### 3. 09:01 서비스 다운 (2025-09-08)
|
||||
- 09:01:15 크론 실행 시 rb8001 다운 ({"failed":3})
|
||||
- 11:33 재시작 (OOM Kill 추정)
|
||||
|
||||
## 해결 조치
|
||||
|
||||
### 완료
|
||||
1. 에러 로깅 개선
|
||||
```python
|
||||
error_msg = str(e) or f"{type(e).__name__}: {repr(e)}"
|
||||
logger.error(f"error: {error_msg}", exc_info=True)
|
||||
```
|
||||
|
||||
**빈 문자열을 반환하는 예외들**:
|
||||
- `MemoryError`: 메모리 부족 시 발생, str() 시 빈 문자열
|
||||
- `aiohttp.client_exceptions.InvalidURL`: URL 문제, str() 시 빈 문자열
|
||||
- 일부 시스템 레벨 예외들
|
||||
2. 스케줄 분리: 헤드라인 09:00 → 09:10
|
||||
|
||||
### 3. 관측성 부족
|
||||
|
||||
**현재 로깅의 문제점**:
|
||||
- 예외 타입 정보 누락
|
||||
- 스택 트레이스 미포함
|
||||
- 요청 ID 연계 없음
|
||||
- 타임스탬프만으로 상관관계 분석 어려움
|
||||
|
||||
## 재현 시나리오
|
||||
### 필요
|
||||
1. 브라우저 풀 구현 (메모리 효율화)
|
||||
2. 재시도 로직 (3회, 지수 백오프)
|
||||
3. 메모리 모니터링
|
||||
|
||||
## 검증
|
||||
```bash
|
||||
# 1. 09:00 전후 부하 시뮬레이션
|
||||
docker exec rb8001 python3 -c "
|
||||
import asyncio
|
||||
import aiohttp
|
||||
# 메모리 확인
|
||||
docker stats rb8001 skill-news
|
||||
|
||||
async def stress_test():
|
||||
tasks = []
|
||||
# 일일 브리핑 시뮬레이션
|
||||
tasks.append(fetch_email_summary())
|
||||
# 헤드라인 요청
|
||||
tasks.append(fetch_headlines())
|
||||
await asyncio.gather(*tasks)
|
||||
# 로그 확인
|
||||
docker logs rb8001 | grep "fetch_naver_headlines"
|
||||
|
||||
async def fetch_email_summary():
|
||||
# skill-email 호출 시뮬레이션
|
||||
pass
|
||||
|
||||
async def fetch_headlines():
|
||||
async with aiohttp.ClientSession() as session:
|
||||
async with session.post('http://localhost:8505/api/news/naver/startup-headlines') as resp:
|
||||
return await resp.json()
|
||||
"
|
||||
```
|
||||
|
||||
## 해결 방안
|
||||
|
||||
### 즉시 적용 가능 (Quick Fix)
|
||||
|
||||
1. **에러 로깅 개선**
|
||||
```python
|
||||
# rb8001/app/commands/skill_commands.py 수정
|
||||
except Exception as e:
|
||||
error_msg = str(e) or f"{type(e).__name__}: {repr(e)}"
|
||||
logger.error(f"fetch_naver_headlines error: {error_msg}", exc_info=True)
|
||||
return {"success": False, "message": error_msg}
|
||||
```
|
||||
|
||||
2. **스케줄 시간 분리**
|
||||
```python
|
||||
# rb8001 크론 설정 변경
|
||||
"09:00": ["daily_briefing"], # 일일 브리핑
|
||||
"09:05": ["companyx_headlines"] # 5분 간격으로 분리
|
||||
```
|
||||
|
||||
3. **타임아웃 값 통일**
|
||||
```python
|
||||
# 모든 서비스에 40초로 통일
|
||||
self.timeout = 40 # Playwright 처리 시간 고려
|
||||
```
|
||||
|
||||
### 중기 개선 (1-2주)
|
||||
|
||||
1. **리소스 풀 분리**
|
||||
```python
|
||||
# skill-news에 브라우저 풀 구현
|
||||
class BrowserPool:
|
||||
def __init__(self, max_browsers=3):
|
||||
self.pool = []
|
||||
self.max_browsers = max_browsers
|
||||
|
||||
async def get_browser(self):
|
||||
# 재사용 가능한 브라우저 반환
|
||||
pass
|
||||
```
|
||||
|
||||
2. **재시도 로직 추가**
|
||||
```python
|
||||
@retry(stop=stop_after_attempt(3),
|
||||
wait=wait_exponential(multiplier=1, min=4, max=10))
|
||||
async def fetch_with_retry():
|
||||
# 지수 백오프로 재시도
|
||||
pass
|
||||
```
|
||||
|
||||
3. **메트릭 수집**
|
||||
```python
|
||||
# 응답 시간, 메모리 사용량 추적
|
||||
metrics = {
|
||||
"p50": calculate_percentile(50),
|
||||
"p95": calculate_percentile(95),
|
||||
"p99": calculate_percentile(99),
|
||||
"memory_peak": get_memory_usage()
|
||||
}
|
||||
```
|
||||
|
||||
### 장기 개선 (1개월+)
|
||||
|
||||
1. **관측성 인프라 구축**
|
||||
- 분산 추적 (Jaeger/Zipkin)
|
||||
- 메트릭 대시보드 (Grafana)
|
||||
- 로그 집계 (ELK Stack)
|
||||
|
||||
2. **큐잉 시스템 도입**
|
||||
- Celery/RabbitMQ로 비동기 작업 관리
|
||||
- 우선순위 큐로 중요 작업 보장
|
||||
|
||||
3. **서킷 브레이커 패턴**
|
||||
- 연속 실패 시 자동 차단
|
||||
- 대체 경로 활성화
|
||||
|
||||
## 검증 방법
|
||||
|
||||
1. **로그 확인**
|
||||
```bash
|
||||
# 개선된 에러 메시지 확인
|
||||
docker logs rb8001 --tail 100 | grep "fetch_naver_headlines error"
|
||||
```
|
||||
|
||||
2. **메모리 모니터링**
|
||||
```bash
|
||||
# 09:00 전후 메모리 사용량
|
||||
docker stats rb8001 skill-news skill-email
|
||||
```
|
||||
|
||||
3. **부하 테스트**
|
||||
```bash
|
||||
# 동시 요청 시뮬레이션
|
||||
# 부하 테스트
|
||||
for i in {1..5}; do
|
||||
curl -X POST http://localhost:8505/api/news/naver/startup-headlines &
|
||||
done
|
||||
wait
|
||||
```
|
||||
|
||||
## 해결 조치 (2025-09-08)
|
||||
|
||||
1. **에러 로깅 개선 적용**: `exc_info=True` 및 예외 타입 출력 추가
|
||||
2. **스케줄 시간 변경**: CompanyX 헤드라인을 09:00 → 09:10으로 변경 (리소스 경합 회피)
|
||||
|
||||
## 교훈
|
||||
|
||||
1. **예외 처리 시 항상 타입 정보 포함**: `str(e)`만으로는 불충분
|
||||
2. **리소스 집약적 작업은 시간 분리**: 동시 실행 피하기
|
||||
3. **관측성은 필수**: 문제 발생 전 모니터링 체계 구축
|
||||
4. **타임아웃 체인 일관성**: 전체 경로의 타임아웃 값 통일
|
||||
5. **재시도와 서킷 브레이커**: 일시적 장애 대응 필수
|
||||
1. MemoryError는 빈 문자열 → type(e).__name__ 필요
|
||||
2. 리소스 집약 작업 시간 분리
|
||||
3. OOM Kill 대비 메모리 제한 설정
|
||||
|
||||
## 관련 파일
|
||||
|
||||
- `/home/happybell80/ivada_project/rb8001/app/commands/skill_commands.py:217-243`
|
||||
- `/home/happybell80/ivada_project/rb8001/app/skills/news_posting_skill.py`
|
||||
- `/home/happybell80/ivada_project/skill_news/app/services/companyx_news_scraper.py`
|
||||
- `/home/happybell80/ivada_project/DOCS/troubleshooting/250714_docker_network_timeout_issues.md`
|
||||
|
||||
## 참고 자료
|
||||
|
||||
- [aiohttp empty error messages issue](https://github.com/aio-libs/aiohttp/issues/5315)
|
||||
- [Python MemoryError empty string behavior](https://stackoverflow.com/questions/31230229/)
|
||||
- 시퀀스 다이어그램: `/DOCS/300_architecture/sequences/daily_briefing_sequences.md`
|
||||
- rb8001/app/commands/skill_commands.py:217-243
|
||||
- skill_news/app/services/companyx_news_scraper.py
|
||||
Loading…
x
Reference in New Issue
Block a user