# task-3018 — 유튜브 러너 Whisper 타임아웃 제거

- **레벨**: Lv.2 · **팀**: dev2-team (오딘) · **작성**: 2026-08-25
- **저장소**: `Jeon-Jonghyuk/InsuWiki` (PR **#9**, draft) + `/home/jay/workspace/services/whisper-gpu/server.py`
- **상태**: 완료 (PR #9 draft — 머지는 ANU 판단)

## SCQA

## S — 상황

t3011 로 유튜브 파이프라인 러너를 배포하자 GPU 100%·76°C 인데 wiki 카드 생성이 **0건**이었다.
클라이언트 로그에 `Read timed out (read timeout=600)` 이 정확히 10분 간격으로 4회 반복됐다.

## C — 문제

ANU 명세는 원인을 **"러너가 앞 요청의 종결을 기다리지 않고 계속 밀어넣어 큐가 적체됐다"** 로
진단하고, 생산자 backpressure(①) 를 본수정으로 지시했다.

## Q — 질문

이 전제가 실제 코드·로그와 일치하는가?

## A — 답변: ★ 전제 ① 은 반증되었다

### 반증 근거 1 — 러너는 이미 완전 순차다

| 확인 대상 | 실측 |
|---|---|
| `main.py` 구조 | 단일 프로세스 · 동기 코드. 영상 for-loop 이 한 건씩 처리 |
| 스레드/asyncio/멀티프로세싱 | **없음** (grep 0건) |
| `transcriber.fetch_whisper_transcription` | `requests.post(timeout=600)` — **블로킹 호출** |
| 실행 주체 | journalctl 상 단일 PID `3597911` |

→ 다음 요청은 앞 요청이 **반환(성공/실패/타임아웃)된 뒤에만** 나갈 수 있다.
   명세가 요구한 "완료 대기(await)" 는 **이미 구현되어 있다**. 추가하면 죽은 코드가 된다.

### 반증 근거 2 — "10분 간격"은 적체가 아니라 순차의 서명이다

```
20:09:35 / 20:19:35 / 20:29:36 / 20:39:37  ← 각 600초 간격
```
동시 폭주였다면 타임아웃은 뭉쳐서 났을 것이다. 정확히 600초씩 벌어진 것은
**한 번에 하나씩** 보내고 하나씩 만료됐다는 뜻이다.

## 실측 근본 원인

```
19:59:44  전사 시작  hcmjH-2UgNE  오디오 8435.0s (2시간 20분)
          ... 43분간 서버 로그 완전 정적 ...
20:09:35  [클라이언트] Read timed out (600s)
20:19:35  [클라이언트] Read timed out
20:29:36  [클라이언트] Read timed out
20:39:37  [클라이언트] Read timed out
20:43:01  전사 완료 (2597초 = 43분 17초)
20:43:01.846  yt-dlp 다운로드 시작  v6oVfFko04A  ┐
20:43:02.020  yt-dlp 다운로드 시작  Rve8rNM_J30  │ 4건이 0.3초 안에
20:43:02.086  yt-dlp 다운로드 시작  EvmWgJ_THDw  │ 한꺼번에 터져 나옴
20:43:02.153  yt-dlp 다운로드 시작  YdA_zlA0oUA  ┘
```

### 원인 A (핵심) — 서버 이벤트 루프가 전사 내내 블로킹된다

`services/whisper-gpu/server.py::run_transcription`:
```python
segments_raw, info = await loop.run_in_executor(None, lambda: model.transcribe(...))
segments = [ ... for seg in segments_raw ]   # ← 실제 GPU 연산이 여기서
```
faster-whisper 의 `model.transcribe()` 는 **제너레이터를 즉시 반환**(lazy)한다.
executor 안에서는 연산이 일어나지 않는다. 실제 전사는 리스트 컴프리헨션에서
소비되며 그 코드는 **이벤트 루프 스레드**에서 돈다.

→ 전사 43분 동안 ASGI 서버 전체 정지. 신규 요청 accept 불가. `/v1/health` 도 응답 불가.
   20:09~20:39 에 도착한 4건의 다운로드 로그가 **하나도 안 찍히다가** 20:43:01 에
   몰려 나온 것이 직접 증거다.

### 원인 B — 600초 고정 타임아웃이 긴 영상에 구조적으로 부족

전사 속도 실측 ≈ 오디오 길이 ÷ 3.2 (8435s → 2597s).
`main.py` 는 이미 `get_video_duration()` 으로 길이를 알면서 타임아웃 산정에 쓰지 않는다.
※ `get_video_duration()` 반환값은 **ISO 8601 문자열**(`"PT2H20M15S"`)이지 초가 아니다 — 파싱 필요.

### 원인 C — 클라이언트가 포기해도 서버 작업은 취소되지 않는다

20:43 이후 GPU 100% 로 처리된 4건은 **아무도 읽지 않을 결과**였다.

### ★ 명세 ② 는 A 없이는 무력하다

"즉시 거절형 큐 한도"(②) 는 옳은 방향이다. 그러나 이벤트 루프가 막혀 있으면
**한도를 검사하는 코드 자체가 실행되지 않는다**. 따라서 A 를 ② 의 선행조건으로
server.py 최소 범위 수정에 포함했다. (명세는 server.py 를 "②만" 으로 제한했으므로
이 확장은 ANU 판단 대상으로 명시한다.)


## 수정 파일별 검증 상태

| 파일 | 변경 | 검증 방법 | status |
|---|---|---|---|
| /home/jay/projects/insuwiki/scripts/youtube-pipeline/youtube_pipeline/transcriber.py | 동적 타임아웃 + ISO8601 파싱 + 429 즉시 fail-closed | pytest 154 passed · 실서버 429 실호출 · 변이주입 3 failed | verified |
| /home/jay/projects/insuwiki/scripts/youtube-pipeline/youtube_pipeline/main.py | duration_seconds 전달 (순차 제어부 1곳) | pytest · grep L252 · 변이주입 1 failed | verified |
| /home/jay/projects/insuwiki/scripts/youtube-pipeline/tests/test_transcriber.py | 봉인 테스트 추가 | pytest 실행 GREEN | verified |
| /home/jay/projects/insuwiki/scripts/youtube-pipeline/tests/test_main_pipeline.py | duration 전달 봉인 | pytest 실행 GREEN | verified |
| /home/jay/projects/insuwiki/scripts/youtube-pipeline/docs/task-3018-root-cause.md | 전제 반증 + 근본원인 기록 | 문서 | verified |
| /home/jay/workspace/services/whisper-gpu/server.py | executor 내 제너레이터 소비 + 즉시거절 큐한도 + 429 전달 | 서비스 재시작 후 실서버 실측 (health 26/26, 429 0.044s) · pytest 50 passed | verified |

## 3 Step Why

**1st Why — 왜 wiki 카드가 0건이었나?**
전사가 전부 실패해 `title_description` 으로 떨어졌고, fail-closed 판정이 카드 생성을 막았다.
즉 카드 0건은 결함이 아니라 **fail-closed 가 정상 동작한 결과**다. 진짜 문제는 전사 실패다.

**2nd Why — 왜 전사가 실패했나?**
클라이언트가 600초에 타임아웃했다. 그런데 명세의 진단("러너가 밀어넣어 적체")은 틀렸다.
러너는 이미 순차였다. 실제로는 2시간 20분짜리 영상 1건이 **43분** 전사되는 동안
서버 이벤트 루프가 통째로 막혀 후속 요청이 accept 조차 되지 않았다.

**3rd Why — 왜 이벤트 루프가 막혔나?**
faster-whisper 의 `model.transcribe()` 가 **제너레이터를 즉시 반환**(lazy)하기 때문이다.
`run_in_executor` 는 제너레이터 생성만 워커로 보냈고, 실제 GPU 연산이 일어나는
세그먼트 소비는 이벤트 루프 스레드에 남아 있었다.
→ 소비까지 executor 안으로 옮기는 것이 근본 해결이며, 실측으로 확인했다
  (GPU 디코드 26.56초 동안 health 26건 전부 정상 응답).

## 수정 내용

### 클라이언트 (InsuWiki PR #9, `task/task-3018-dev2`)
| 파일 | 변경 |
|---|---|
| `youtube_pipeline/transcriber.py` | 동적 타임아웃(`compute_whisper_timeout`) · ISO8601 파싱(`parse_duration_seconds`) · **429 → 재시도 없이 즉시 None**(fail-closed) |
| `youtube_pipeline/main.py` | `transcribe(..., duration_seconds=duration)` 전달 (순차 제어부 1곳만) |
| `tests/test_transcriber.py` · `tests/test_main_pipeline.py` | 봉인 테스트 +41건 |

상수는 전부 환경변수 override: `WHISPER_TIMEOUT_FACTOR`(0.75) · `_MARGIN_SEC`(300) · `_MIN_SEC`(600) · `_MAX_SEC`(5400).

### 서버 (`/home/jay/workspace/services/whisper-gpu/server.py`)
1. **원인 A** — `_transcribe_and_collect()` 로 `model.transcribe()` 호출 + 세그먼트 소비를 묶어
   **executor 안에서 전부** 수행. 이벤트 루프에서 제너레이터를 소비하는 코드 **0**.
2. **원인 ②** — `_gpu_queue_depth` 카운터 + `WHISPER_MAX_QUEUE`(기본 2). 한도 초과 시
   **대기 없이 즉시 429** + `Retry-After`. 공유 진입점 `run_transcription()` 에 두어 3개 엔드포인트 공통 적용.
3. **명세에 없던 사각지대** — `/v1/youtube-transcribe` 의 `except Exception → 500` 이 429를 삼키고
   있었다. `except HTTPException: raise` 를 넣지 않으면 **클라이언트는 429 를 영원히 못 본다**
   (= 즉시거절 기능 전체가 죽은 코드). 나머지 두 엔드포인트는 이미 같은 규약을 갖고 있었다.

## 검증 결과 — baseline ↔ post-fix 실측 대조

측정 상세: `memory/reports/task-3018-baseline.md` (수정 전) · `task-3018-postfix.md` (수정 후)

| # | 항목 | baseline 실측 | post-fix 실측 | 판정 |
|---|---|---|---|---|
| 1 | 유휴 `/v1/health` | 18.4~20.5 ms | 18.3~19.1 ms | 조건 동등 |
| 2 | **GPU 디코드 중 health 타임아웃** | **16건 (100% 무응답)** | **0건 (26/26 ~18ms)** | ★ 완전 해소 |
| 3 | **2번째 요청 첫 핸들러 로그 지연** | **22.855초** | **0.006초** | ★ 해소 (~3,800배) |
| 4 | 2번째 요청 다운로드 완료 시점 | A 전사 완료 **후** | **A 전사 도중** | ★ 해소 |
| 5 | 큐 한도 초과 시 | (기능 없음) 무한 대기 | **429 in 0.044~0.049초** + `Retry-After: 300` | ★ 신규 동작 |
| 6 | YouTube 엔드포인트 429 전달 | (기능 없음) | **429** (500 아님) | ★ 확인 |
| 7 | 사고 영상 클라이언트 타임아웃 | 600초 고정 → **실패**(2597초 전사) | **5400초** (여유 2803초) | ★ 해소 |
| 8 | 600초 대기성 타임아웃 도달 | — | **0건** | ★ 미재발 |
| 9 | fail-closed (429 → title_description) | (429 없음) | **실서버 429 실호출로 실증** | ★ 유지 |
| 10 | 회귀 (파이프라인 / whisper) | 113 / 50 | **154 / 50 passed** | 회귀 0건 |
| 11 | 콜드 스타트 부분 지연 | 0.784785 s | 0.784670 s | 변화 없음 (의도된 미수정) |

**V1 결정적 증거**: GPU 디코드 26.56초 동안 health 폴링 **26건 전부 ~18ms 정상 응답**.
baseline 은 같은 구간 100% 무응답이었다.
**V2 결정적 증거**: 두 번째 요청의 yt-dlp 다운로드가 **A 전사 도중에 시작·완료**됐다
(23:14:51.634 발사 → 23:14:54.050 완료, A 는 23:15:14.458 완료). baseline 에서는 A 완료 후에야 시작됐다.
이후 B 의 전사가 A 완료까지 기다린 것은 `_gpu_lock` 에 의한 **정상적인 GPU 직렬화**이지 루프 블로킹이 아니다.

### 봉인 (변이 주입 실증)
| 변이 | 결과 |
|---|---|
| `timeout=timeout` → `600` 고정 회귀 | **3 failed** |
| 429 분기 삭제 | **1 failed** |
| `main.py` duration 미전달 | **1 failed** |

429 테스트는 **정상 포맷의 위조값**(`status=429` + `{"text": "위조된 성공 본문"}`)을 쓰고
`resp.json.assert_not_called()` · `call_count == 1` 로 봉인한다. malformed 입력만 쓰지 않았다.

## L1 스모크테스트

- **서버 재시작**: **성공** — `whisper-gpu.service` 재시작 (`MainPID=598091`,
  `ExecMainStartTimestamp=2026-08-25 23:11:31 KST`). 수정 코드가 실제 구동 중이다.
- **API 응답 확인**: **성공** — 실서버 curl 실측
  - `/v1/health` 200, 유휴 18.3~19.1 ms
  - 동시 4건 발사 → 2건 `200`, 2건 **`429` (wall 0.044s / 0.049s)** + `retry-after: 300`
  - 429 본문 원문: `{"detail":"Whisper GPU 큐 포화 (대기/실행 2건 >= 한도 2건). 잠시 후 다시 시도하세요."}`
  - `/v1/youtube-transcribe` 도 429 반환(500 아님) 실트래픽 확인
  - 실서버 429 → `transcriber.transcribe()` 실호출 → `source == "title_description"` **실증(mock 아님)**
- **스크린샷**: 해당없음 (백엔드 전용, UI 변경 0)

### ★ 파이프라인 전체 수동 실행은 의도적으로 하지 않았다
`main.py` 는 `yt_update_last_crawled()` 를 per-video try/except **밖**에서 호출한다
(`new_videos` 가 비어있지 않으면 성공·실패 무관하게 커서 전진).
현재 **Gemini API 키가 무효**(실측 `HTTP 400 INVALID_ARGUMENT`)라 요약이 전부 실패하므로,
전체 실행 시 **실패한 영상들의 커서가 전진해 영구 유실**된다.
따라서 변경된 경로를 **컴포넌트 수준 + 실서버 대상**으로 검증했다.

## QC / trip-wire 실측

| 항목 | 실측 | 근거 |
|---|---|---|
| Critical7 | **0** | red-team 지적 5건 전부 오탐 판정 (아래) |
| PII net-new | **0** | diff 전량 패턴 스캔 0건 |
| 회귀 실패 | **0** | 154 passed / 50 passed |
| forbidden_paths 침범 | **0** | 변경 5파일 전부 `scripts/youtube-pipeline/**` + `server.py` |
| nonce | **task-3018** 일치 | — |

### red-team 오탐 판정 근거
- `re.compile(...)` **4건** (transcriber L33, server L367·L375·L759) → 전부 **리터럴 정적 패턴**.
  스캐너가 `compile(` 부분일치로 "Code Injection" 분류. 메모리에 기록된 알려진 오탐.
- `asyncio.create_subprocess_exec(` (server L775) → **인자 리스트 방식**(셸 미경유)이고
  `video_id` 는 `^[a-zA-Z0-9_-]{11}$` 로 사전 검증됨. **또한 우리 hunk 밖 선재 코드**.
- server.py 지적 4건은 **전부 task-3018 hunk 밖**이다 (net-new critical = 0).
- code-validator `Execution Test ❌` 는 **선재 현상** — master 원본도 동일하게 실패한다
  (패키지 상대임포트 모듈을 단독 실행하는 검사기 한계).

## 잔여 위험 (헤임달 실측 · 전부 ANU 판단 대상)

**1. (중) YouTube 경로의 429 는 다운로드를 낭비한 뒤 나온다**
큐 체크는 `run_transcription()`(server.py:446) 인데 `/v1/youtube-transcribe` 는
yt-dlp 다운로드를 **모두 마친 뒤**(:825) 이를 호출한다.
실측: 직접 경로 429 = **0.044초** vs YouTube 경로 429 = **4.302초**(대부분 다운로드).
GPU 는 정상 보호되고 임시파일도 정리되므로 기능적 결함은 아니나,
2시간급 영상이면 다운로드 수 분이 통째로 버려진다. 개선하려면 다운로드 **이전** 선체크 경로가 필요하다.

**2. (중) 동적 타임아웃이 큐 대기 시간을 고려하지 않는다**
`WHISPER_MAX_QUEUE=2` 는 앞선 1건 대기를 허용하는데(V3 REQ1 실측 wall 53.966초 = 대기 27 + 전사 27),
`compute_whisper_timeout()` 은 **자기 영상 길이만으로** 산정한다.
실측 배속 3.25~3.38x 기준 추정:

| 영상 길이 | timeout | 대기+전사 최악 | 판정 |
|---:|---:|---:|:---|
| **8,435초 (사고 영상)** | 5400 | 5112 | **OK (여유 5.3%)** |
| 8,911초 (2h28m) 초과 | 5400 | 5401+ | **TIMEOUT** |

사고 영상은 **간신히** 통과하는 수준이다. 다만 타임아웃해도 fail-closed 로 떨어져
**데이터 오염은 없다**(V5 실증). 즉 안전하게 실패하되 긴 영상 전사는 실패할 수 있다.
★ **오딘 권고**: `WHISPER_MAX_QUEUE=1` 로 두면 대기 자체가 사라져 이 위험이 소멸한다.
러너가 이미 순차이므로 실질 손실이 없고, 명세의 "기다리게 하지 마라" 취지에 더 충실하다.
다만 공유 서비스의 기본값 변경이므로 임의로 하지 않았다.

**3. (하) 콜드 스타트 9초 블로킹 존치**
`get_model_instance()` 가 executor 밖 동기 호출이라 모델 언로드(600초 유휴) 후 첫 요청마다
약 9초 부분 블로킹(health 0.785s)이 재발한다. 명세의 "server.py 최소 범위" 를 지켜 미수정.
43분 → 9초이므로 DoD 에는 영향 없으나 헬스체크 감시가 장애로 오판할 수 있다.

**4. 긴 영상 실전사 미실증**
검증 전사는 전부 75~90초 짧은 오디오다(GPU 장시간 점유 금지 준수).
위험 2의 표는 실측 배속 기반 **추정**이며 2,597초 전사를 재현한 것이 아니다.

**5. 고아 임시파일 (범위 밖 별개 문제)**
`/tmp/whisper_yt_EvmWgJ_THDw.webm`(42MB) · `YdA_zlA0oUA.webm`(134MB) — 20:43 사고 당시 생성.
정상 종료 경로 정리는 동작하나 비정상 종료 시 176MB 급 잔여물이 남는다. 보존해 두었다.

## 미해결 / ANU 판단 필요

1. **server.py 범위 확장** — 원인 A 수정 포함 (②의 선행조건). 명세는 "②만" 이었다.
2. **Gemini API 키 무효** — 실측 `HTTP 400 INVALID_ARGUMENT / "API key not valid"`.
   → 검증 항목 5(전사 성공 시 wiki 카드 실제 생성)를 **종단으로 실증할 수 없다**.
   `summarizer.py` 는 수정 금지 대상이고 키 로테이션은 범위 밖이다.
3. **긴 영상 정책** — 2h20m 영상 1건이 서버를 43분 점유한다. 길이 상한을 둘지는
   처리 대상 변경(=행동 변경)이므로 임의로 결정하지 않았다.
4. **workspace 커밋 미실행** — `services/whisper-gpu/server.py` 변경은 **디스크·구동 프로세스에 반영**되었으나
   git 커밋은 하지 않았다. 사유 2가지:
   (a) workspace 는 `main` 브랜치이고 훅이 `task/task-N-bot` 브랜치를 요구하는데,
       브랜치 전환은 다른 봇의 staged 파일 79개를 포함한 **공유 워크스페이스 전체**에 영향을 준다.
   (b) 같은 파일에 **우리가 만들지 않은 선재 미커밋 델타**(용어교정 가드, task-2980 계열)가 섞여 있어
       커밋하면 남의 작업이 함께 들어간다.
   → 감사용으로 **task-3018 hunk 만 분리**한 패치를 `memory/reports/task-3018-server-ours.diff` 에 저장했다
     (전체 6 hunk 중 우리 것 4 / 선재 2). `test_server.py` 도 선재 델타이며 우리는 **미수정**
     (mtime 2026-08-20 09:45, task-3018 흔적 0건).
5. **파이프라인 재가동** — 명세대로 이 태스크에서 하지 않았다. `insuwiki-youtube-pipeline.timer` = **inactive 유지**.
   재가동 전 **Gemini 키 로테이션이 선행되어야 한다**(무효 상태에서 켜면 커서만 전진해 영상이 유실된다).

## 세션 통계
- 총 도구 호출: 0회


## 세션 통계
- 총 도구 호출: 0회


## 세션 통계
- 총 도구 호출: 0회