---
task_id: task-3018
scope: task
doc_type: postfix-verification
author: 헤임달 (Heimdall) / 개발2팀 QA
date: 2026-08-25
target: whisper-gpu.service (수정 후 구동 프로세스, PID 598091)
baseline_ref: memory/reports/task-3018-baseline.md
---

# task-3018 수정 후(post-fix) 검증

## S (상황)

`whisper-gpu.service` 가 2026-08-25 23:11:31 KST 에 재시작되어
`/home/jay/workspace/services/whisper-gpu/server.py` 의 **수정 코드**를 구동 중이다.

- 측정 시각: 2026-08-25 23:13 ~ 23:21 KST
- 서비스 무결성: 측정 전후 `MainPID=598091`, `ActiveEnterTimestamp=Tue 2026-08-25 23:11:31 KST`,
  `NRestarts=0` **불변** (측정 중 재시작 없음)
- `insuwiki-youtube-pipeline.timer` = `inactive` 유지 (측정 전/후 확인)
- 클라이언트: `/home/jay/projects/insuwiki` 브랜치 `task/task-3018-dev2` 커밋 `72dc6e7`

수정 코드가 실제로 구동 프로세스에 반영되었음을 확인한 근거 (`server.py` grep):
`_gpu_queue_depth`(:61), `WHISPER_MAX_QUEUE_DEFAULT = 2`(:57), `_transcribe_and_collect`(:472),
`Retry-After`(:459), `except HTTPException: raise`(:826-827).
런타임 확인은 V3 의 실제 429 응답으로 별도 실증했다(정적 grep 만으로 판정하지 않음).

★ 구조 확인: 큐 체크(`:446`)와 카운터 증가(`:466`) 사이에 `await` 가 없다 → 단일 스레드
이벤트 루프에서 **원자적**이다. 감소는 `finally`(:496)에 있어 예외·취소 시에도 복원된다.

## 유휴 기준선 대조 (사과 대 사과 전제 확인)

| 시점 | `/v1/health` 유휴 응답 |
|---|---|
| baseline (23:03) | 0.018685 / 0.018389 / 0.018744 |
| **post-fix 측정 전 (23:13:08)** | **0.019086 / 0.018319 / 0.018472** |
| **post-fix 측정 후 (23:21:16)** | **0.018807 / 0.018860 / 0.018522** |

유휴 성능 동일(약 18~19ms). 측정 조건이 동등함을 확인했다.

---

# V1. 이벤트 루프 블로킹 해소 (원인 A) — **해소 확인**

baseline RUN 1 과 동일 조건: 콜드 스타트(모델 미로딩) 상태에서 `v6oVfFko04A` 전사 발사 +
`/v1/health` 1초 간격 · `-m 3` 폴링.

```
CURSOR=2026-08-25 23:13:21
REQ_A_SENT_AT=2026-08-25T23:13:22+09:00
REQ_A_DONE_AT=2026-08-25T23:14:00+09:00 wall=38.521807420 curl=200 38.503008
```

`/tmp/t3018p/poll.log` 원문 (38건 전량):

```
001 2026-08-25T23:13:21+09:00 OK   200 0.018803
002 2026-08-25T23:13:22+09:00 OK   200 0.026622
003 2026-08-25T23:13:23+09:00 OK   200 0.018530
004 2026-08-25T23:13:24+09:00 FAIL curl_exit=28 (000 3.002081)
005 2026-08-25T23:13:28+09:00 FAIL curl_exit=28 (000 3.003024)
006 2026-08-25T23:13:32+09:00 OK   200 0.784670
007 2026-08-25T23:13:34+09:00 OK   200 0.018596
008 2026-08-25T23:13:35+09:00 OK   200 0.018387
009 2026-08-25T23:13:36+09:00 OK   200 0.018236
010 2026-08-25T23:13:37+09:00 OK   200 0.018501
011 2026-08-25T23:13:38+09:00 OK   200 0.018296
012 2026-08-25T23:13:39+09:00 OK   200 0.017991
013 2026-08-25T23:13:40+09:00 OK   200 0.018447
014 2026-08-25T23:13:41+09:00 OK   200 0.017998
015 2026-08-25T23:13:42+09:00 OK   200 0.018087
016 2026-08-25T23:13:43+09:00 OK   200 0.018496
017 2026-08-25T23:13:44+09:00 OK   200 0.018273
018 2026-08-25T23:13:45+09:00 OK   200 0.018380
019 2026-08-25T23:13:46+09:00 OK   200 0.018081
020 2026-08-25T23:13:48+09:00 OK   200 0.018083
021 2026-08-25T23:13:49+09:00 OK   200 0.018279
022 2026-08-25T23:13:50+09:00 OK   200 0.018771
023 2026-08-25T23:13:51+09:00 OK   200 0.018195
024 2026-08-25T23:13:52+09:00 OK   200 0.018792
025 2026-08-25T23:13:53+09:00 OK   200 0.018580
026 2026-08-25T23:13:54+09:00 OK   200 0.018258
027 2026-08-25T23:13:55+09:00 OK   200 0.018324
028 2026-08-25T23:13:56+09:00 OK   200 0.018174
029 2026-08-25T23:13:57+09:00 OK   200 0.017994
030 2026-08-25T23:13:58+09:00 OK   200 0.018552
031 2026-08-25T23:13:59+09:00 OK   200 0.018405
032 2026-08-25T23:14:00+09:00 OK   200 0.018106
033 2026-08-25T23:14:01+09:00 OK   200 0.018563
034 2026-08-25T23:14:02+09:00 OK   200 0.018549
035 2026-08-25T23:14:03+09:00 OK   200 0.022222
036 2026-08-25T23:14:04+09:00 OK   200 0.019328
037 2026-08-25T23:14:05+09:00 OK   200 0.018531
038 2026-08-25T23:14:06+09:00 OK   200 0.018681
```

집계: **OK 36건 / FAIL(3초 타임아웃) 2건.**

## V1 서버 로그와의 위상 대조

> 인용 규칙: baseline 과 동일하게 `journalctl --user -u whisper-gpu.service --no-pager -o short-iso`
> 출력에서 공통 접두사 `aidevserver start-whisper-gpu.sh[598093]:` 와 `GET /v1/health` 접근로그 줄을
> 제거한 **발췌**다. 타임스탬프·메시지 본문은 무가공이다.

```
2026-08-25 23:13:22,078 [INFO] whisper-gpu: yt-dlp 다운로드 시작: video_id=v6oVfFko04A
2026-08-25 23:13:24,521 [INFO] whisper-gpu: yt-dlp 다운로드 완료: video_id=v6oVfFko04A
2026-08-25 23:13:24,537 [INFO] whisper-gpu: 다운로드된 오디오 파일: /tmp/whisper_yt_v6oVfFko04A.webm
2026-08-25 23:13:24,541 [INFO] whisper-gpu: 전사 모델 선택: model=large-v3 duration=89.9s video_id=v6oVfFko04A
2026-08-25 23:13:24,541 [INFO] whisper-gpu: 전사 시작: model=large-v3 language=ko file=/tmp/whisper_yt_v6oVfFko04A.webm
2026-08-25 23:13:26,740 [INFO] whisper-gpu: WhisperModel 로딩: size=large-v3 device=cuda compute_type=int8
2026-08-25 23:13:33,609 [INFO] whisper-gpu: WhisperModel 로딩 완료: size=large-v3
2026-08-25 23:13:34,009 [INFO] faster_whisper: Processing audio with duration 01:29.877
2026-08-25 23:14:00,569 [INFO] whisper-gpu: 전사 완료: language=ko duration=89.9s segments=27
2026-08-25 23:14:00,569 [INFO] whisper-gpu: 임시 파일 삭제 완료: /tmp/whisper_yt_v6oVfFko04A.webm
```

| 구간 | 서버 로그 시각 | baseline health | **post-fix health** | 판정 |
|---|---|---|---|---|
| yt-dlp 다운로드 (async subprocess) | 23:13:22.078 → 23:13:24.521 | 001~003 OK ~20ms | 001~003 **OK ~19ms** | 동일 (원래 정상) |
| `get_model_instance()` 진입~모델 로딩 | 23:13:24.541 → 23:13:33.609 | 004·005 타임아웃, 006 OK 0.785s | 004·005 **타임아웃**, 006 **OK 0.784670s** | **변화 없음 (의도된 미수정)** |
| **GPU 디코드 (`segments` 소비)** | **23:13:34.009 → 23:14:00.569 (26.56초)** | **007~012 6연속 전부 타임아웃** | **007~032 26건 전부 OK, 전량 ~18ms** | **★ 완전 해소** |
| 전사 완료 이후 | 23:14:00.569 ~ | 013 이후 정상 복귀 | 033~038 OK ~18ms | 동일 |

## V1 판정

**원인 A(이벤트 루프 블로킹) = 해소.**

결정적 증거: **GPU 디코드 구간 26.56초 동안 health 폴링 26건이 전부 ~18ms 정상 응답**했다.
baseline 에서 이 구간은 100% 무응답이었다. `_transcribe_and_collect()` 로 제너레이터 소비를
executor 안으로 옮긴 것이 실제로 이벤트 루프를 해방시켰음을 실측으로 확인했다.

### ★ 잔여 사항 — 모델 콜드 스타트 구간 (알려진 미수정, 회귀 아님)

`get_model_instance()`(`server.py:470`)는 executor 밖 동기 호출로 **의도적으로 유지**되었다.
이 구간의 동작은 baseline 과 **사실상 완전히 동일**하다:

| 항목 | baseline | post-fix | 차이 |
|---|---|---|---|
| 타임아웃 건수 | 2건 (004·005) | 2건 (004·005) | 0 |
| 부분 지연 폴링 응답시간 | **0.784785s** | **0.784670s** | -0.000115s |
| 블로킹 구간 길이 | 23:03:54.120→23:04:03.360 ≈ **9.24초** | 23:13:24.541→23:13:33.609 ≈ **9.07초** | -0.17초 |

즉 **잔여 블로킹은 콜드 스타트 1회당 약 9초**이며, 모델이 로딩된 뒤에는 재발하지 않는다
(V2·V3 의 웜 상태 실행에서 이 구간의 타임아웃 0건). 회귀가 아니라 **미수정 범위가
정확히 그대로 남은 것**이다.

### 타임아웃 건수 대조

- **GPU 디코드 구간(주 원인)**: baseline **16건**(RUN1-A 6 + RUN1-B 5 + RUN3 5) → post-fix **0건**
- **콜드 스타트 구간(미수정)**: baseline 2건/회 → post-fix 2건/회 (동일)

---

# V2. 두 번째 요청 즉시 접수 (원인 A·C) — **해소 확인**

baseline RUN 3 과 동일: A(`v6oVfFko04A`) 전사 시작 관측 후 **+4초**에 B(`Rve8rNM_J30`) 발사.

클라이언트 로그 (`/tmp/t3018p/v2.log`):
```
CURSOR=2026-08-25 23:14:45
A_SENT=2026-08-25T23:14:45.125366880
A_TRANSCRIBE_START_SEEN=2026-08-25T23:14:47.625699066
B_SENT=2026-08-25T23:14:51.627741454
A_RESULT http_time=200 29.331745 wall=29.335493250 A_DONE=2026-08-25T23:15:14.465087388
B_RESULT http_time=200 46.392431 wall=46.394161855 B_DONE=2026-08-25T23:15:38.025422065
```

서버 로그 원문(발췌 규칙 동일):
```
2026-08-25 23:14:45,132 [INFO] whisper-gpu: yt-dlp 다운로드 시작: video_id=v6oVfFko04A
2026-08-25 23:14:47,526 [INFO] whisper-gpu: yt-dlp 다운로드 완료: video_id=v6oVfFko04A
2026-08-25 23:14:47,543 [INFO] whisper-gpu: 다운로드된 오디오 파일: /tmp/whisper_yt_v6oVfFko04A.webm
2026-08-25 23:14:47,546 [INFO] whisper-gpu: 전사 모델 선택: model=large-v3 duration=89.9s video_id=v6oVfFko04A
2026-08-25 23:14:47,546 [INFO] whisper-gpu: 전사 시작: model=large-v3 language=ko file=/tmp/whisper_yt_v6oVfFko04A.webm
2026-08-25 23:14:47,931 [INFO] faster_whisper: Processing audio with duration 01:29.877
2026-08-25 23:14:51,634 [INFO] whisper-gpu: yt-dlp 다운로드 시작: video_id=Rve8rNM_J30
2026-08-25 23:14:54,050 [INFO] whisper-gpu: yt-dlp 다운로드 완료: video_id=Rve8rNM_J30
2026-08-25 23:14:54,066 [INFO] whisper-gpu: 다운로드된 오디오 파일: /tmp/whisper_yt_Rve8rNM_J30.webm
2026-08-25 23:14:54,069 [INFO] whisper-gpu: 전사 모델 선택: model=large-v3 duration=75.3s video_id=Rve8rNM_J30
2026-08-25 23:15:14,458 [INFO] whisper-gpu: 전사 완료: language=ko duration=89.9s segments=27
2026-08-25 23:15:14,459 [INFO] whisper-gpu: 임시 파일 삭제 완료: /tmp/whisper_yt_v6oVfFko04A.webm
2026-08-25 23:15:14,459 [INFO] whisper-gpu: 전사 시작: model=large-v3 language=ko file=/tmp/whisper_yt_Rve8rNM_J30.webm
2026-08-25 23:15:14,793 [INFO] faster_whisper: Processing audio with duration 01:15.243
2026-08-25 23:15:38,020 [INFO] whisper-gpu: 전사 완료: language=ko duration=75.2s segments=7
2026-08-25 23:15:38,020 [INFO] whisper-gpu: 임시 파일 삭제 완료: /tmp/whisper_yt_Rve8rNM_J30.webm
```

| 항목 | baseline (RUN3) | **post-fix** |
|---|---|---|
| B 요청 클라이언트 발사 | 23:07:27.900 | 23:14:51.627741 |
| **B 의 `yt-dlp 다운로드 시작` 로그** | 23:07:50.755 | **23:14:51.634** |
| **B 발사 → 첫 핸들러 로그 지연** | **22.855초** | **0.006초 (6ms)** |
| B 다운로드 완료 시각 | 23:07:53.116 (A 완료 후) | **23:14:54.050 (A 전사 한복판)** |
| A 전사 완료 | 23:07:50.753 | 23:15:14.458 |
| B 전사 시작 | 23:07:53.136 | 23:15:14.459 |

## V2 판정 — **해소.** 지연 22.855초 → **0.006초 (약 3,800배 개선)**

★ 핵심은 지연 수치만이 아니다. **B 의 yt-dlp 다운로드가 A 의 전사 도중에 시작되어 도중에
완료되었다**(23:14:51.634 발사 → 23:14:54.050 완료, A 는 23:15:14.458 에야 완료).
baseline 에서는 B 의 다운로드가 A 전사 완료 **후에야** 시작됐다. 이벤트 루프가 전사 중에도
살아서 신규 요청을 라우팅·처리하고 있다는 직접 증거다.

B 의 전사 자체는 A 완료(23:15:14.458) 직후 23:15:14.459 에 시작됐는데, 이것은
**`_gpu_lock` 에 의한 정상적인 GPU 직렬화**이지 이벤트 루프 블로킹이 아니다
(다운로드·라우팅은 이미 병렬로 끝나 있었다).

---

# V3. 즉시 거절형 큐 한도 (원인 ②) — **동작 확인**

`/v1/transcribe`(multipart) 로 동일 90초 오디오를 **4건 동시** 발사.
이 엔드포인트를 쓴 이유: yt-dlp 다운로드 변수를 제거하고 **공유 게이트인 `run_transcription()`
자체의 거절 지연**을 순수하게 측정하기 위함이다(YouTube 경로는 아래 별도 실증).

`/tmp/t3018p/v3.log` 원문:
```
CURSOR=2026-08-25 23:16:49
REQ1 sent=23:16:49.590549173 http=200 wall=53.965914974
REQ2 sent=23:16:49.590533724 http=200 wall=27.012207835
REQ3 sent=23:16:49.590625469 http=429 wall=.049230495
REQ4 sent=23:16:49.590894089 http=429 wall=.044278646
```

| 요청 | 발사 시각 | HTTP | **응답까지 wall time** | 판정 |
|---|---|---|---|---|
| REQ1 | 23:16:49.590549 | 200 | 53.966초 | 접수 → GPU 락 대기 27초 + 전사 27초 |
| REQ2 | 23:16:49.590534 | 200 | 27.012초 | 접수 → 즉시 전사 |
| **REQ3** | 23:16:49.590625 | **429** | **0.049초** | **즉시 거절** |
| **REQ4** | 23:16:49.590894 | **429** | **0.044초** | **즉시 거절** |

★ **429 가 44~49ms 만에 도착했다.** 기다렸다 거절한 것이 아니다(대기 시 27초 이상이었을 것).

## 429 응답 헤더 원문 (REQ3)
```
HTTP/1.1 100 Continue

HTTP/1.1 429 Too Many Requests
date: Tue, 25 Aug 2026 14:16:49 GMT
server: uvicorn
retry-after: 300
content-length: 107
content-type: application/json
```

## 429 응답 본문 원문 (REQ3·REQ4 동일)
```json
{"detail":"Whisper GPU 큐 포화 (대기/실행 2건 >= 한도 2건). 잠시 후 다시 시도하세요."}
```

`Retry-After: 300` 헤더 정상 부착 확인.

## 서버 경고 로그 원문
```
2026-08-25 23:16:49,621 [INFO] whisper-gpu: 모델 선택: hint=large-v3 auto=large-v3 chosen=large-v3 duration=89.9s
2026-08-25 23:16:49,621 [INFO] whisper-gpu: 전사 시작: model=large-v3 language=ko file=/tmp/whisper_upload_kkyexg27.webm
2026-08-25 23:16:49,625 [INFO] whisper-gpu: 모델 선택: hint=large-v3 auto=large-v3 chosen=large-v3 duration=89.9s
2026-08-25 23:16:49,630 [INFO] whisper-gpu: 모델 선택: hint=large-v3 auto=large-v3 chosen=large-v3 duration=89.9s
2026-08-25 23:16:49,630 [WARNING] whisper-gpu: GPU 큐 한도 초과 — 즉시 거절(429): 대기/실행 2건, 한도 2건, file=/tmp/whisper_upload_9_z3hh5n.webm
INFO:     127.0.0.1:33856 - "POST /v1/transcribe HTTP/1.1" 429 Too Many Requests
2026-08-25 23:16:49,636 [INFO] whisper-gpu: 모델 선택: hint=large-v3 auto=large-v3 chosen=large-v3 duration=89.9s
2026-08-25 23:16:49,636 [WARNING] whisper-gpu: GPU 큐 한도 초과 — 즉시 거절(429): 대기/실행 2건, 한도 2건, file=/tmp/whisper_upload_0e3880ic.webm
INFO:     127.0.0.1:33862 - "POST /v1/transcribe HTTP/1.1" 429 Too Many Requests
2026-08-25 23:17:16,599 [INFO] whisper-gpu: 전사 완료: language=ko duration=89.9s segments=27
2026-08-25 23:17:16,599 [INFO] whisper-gpu: 전사 시작: model=large-v3 language=ko file=/tmp/whisper_upload_diyre52v.webm
2026-08-25 23:17:43,550 [INFO] whisper-gpu: 전사 완료: language=ko duration=89.9s segments=27
```

거절 결정이 발사 후 **40ms 이내**(23:16:49.590 → 23:16:49.630)에 로그로 남았다.

## YouTube 엔드포인트 429 실증 (수정 3번 항목 — 429가 500으로 뭉개지지 않음)

V5 에서 실제 클라이언트 호출로 유도한 429:
```
2026-08-25 23:18:55,388 [WARNING] whisper-gpu: GPU 큐 한도 초과 — 즉시 거절(429): 대기/실행 2건, 한도 2건, file=/tmp/whisper_yt_v6oVfFko04A.webm
INFO:     127.0.0.1:52762 - "POST /v1/youtube-transcribe HTTP/1.1" 429 Too Many Requests
```
**`/v1/youtube-transcribe` 가 500 이 아닌 429 를 반환**했다. `except HTTPException: raise`
수정이 실트래픽에서 동작함을 확인.

## V3 판정 — **동작 확인.** 다만 아래 한계가 있다(★ 잔여 위험 1 참조)

---

# V4. 10분(600초) 대기성 타임아웃 미재발 — **확인**

V1~V5 전 구간에서 측정된 모든 요청의 wall time:

| 시험 | 요청 | wall time | 600초 대비 |
|---|---|---|---|
| V1 | A (`v6oVfFko04A`, 콜드) | 38.522초 | 6.4% |
| V2 | A (`v6oVfFko04A`) | 29.335초 | 4.9% |
| V2 | B (`Rve8rNM_J30`, 큐 대기 포함) | 46.394초 | 7.7% |
| V3 | REQ1 (큐 대기 27초 포함) | **53.966초 (최댓값)** | **9.0%** |
| V3 | REQ2 | 27.012초 | 4.5% |
| V3 | REQ3 / REQ4 | 0.049 / 0.044초 | 0.008% |
| V5 | FILL1 | 53.946초 | 9.0% |
| V5 | FILL2 | 26.932초 | 4.5% |
| V5 | 클라이언트 `transcribe()` (429 경로) | 4.302초 | 0.7% |

**최대 wall time = 53.966초.** 600초의 9.0%. 600초 근처까지 매달린 요청은 **0건**.

단, 본 측정은 전부 75~90초 짧은 오디오다. **긴 영상(사고 당시 8,435초)으로는 미실증**이며
GPU 장기 점유 금지 지침에 따라 시도하지 않았다. 긴 영상에 대한 타임아웃 충분성은
V6 의 계산값 검증으로 대체했다(실전사 미실행).

---

# V5. fail-closed 유지 — **유지 확인 (실호출 실증)**

## V5-1. 실서버 429 → 클라이언트 `transcribe()` 실호출 (★ mock 아님)

방법: `/v1/transcribe` 업로드 2건으로 GPU 큐를 채워(depth=2) 두고, 그 상태에서
`youtube_pipeline.transcriber.transcribe()` 를 **실제로 호출**했다.
`main.py` 는 실행하지 않았다(커서 전진 위험 회피 — 컴포넌트 수준 호출).

실행 출력 원문:
```
2026-08-25 23:18:55,457 [WARNING] youtube_pipeline.transcriber: Whisper 서버 혼잡 — 즉시 거절(429), 전사 생략: v6oVfFko04A
2026-08-25 23:18:55,457 [WARNING] youtube_pipeline.transcriber: 자막/STT 모두 실패 — 제목+설명 fallback
============================================================
RESULT source = 'title_description'
elapsed       = 4.302s
text[:80]     = '영상 제목: 테스트 제목\n\n영상 설명:\n테스트 설명'
is title_description ? True
============================================================
```

대응 서버 로그:
```
2026-08-25 23:18:55,388 [WARNING] whisper-gpu: GPU 큐 한도 초과 — 즉시 거절(429): 대기/실행 2건, 한도 2건, file=/tmp/whisper_yt_v6oVfFko04A.webm
INFO:     127.0.0.1:52762 - "POST /v1/youtube-transcribe HTTP/1.1" 429 Too Many Requests
```

★ **실서버가 실제로 반환한 429 를 클라이언트가 받아 `source == "title_description"` 으로
떨어졌다. mock 이 아닌 실호출로 실증됨.**

## V5-2. `main.py` fail-closed 분기 존치 확인 (grep, 코드 미수정)

`/home/jay/projects/insuwiki/scripts/youtube-pipeline/youtube_pipeline/main.py`:

```
257:                    is_title_only = transcript.source == "title_description"
264:                    if not is_title_only:          # 요약 생성 금지
298:                    if not is_title_only:
317:                    if not is_title_only and summary_text and embedding:   # insurance_chunks 저장 금지
347:                            "hasTranscript": not is_title_only,
360:                    if not is_title_only and summary_text:                 # wiki 카드 게시 조건
380:                            "wiki 카드 생성 스킵 (전사 없음/title_description): %s",
```

`:360` 의 `if not is_title_only and summary_text:` 의 `else` 절(`:378-382`)이 그대로 존재:
```python
                    else:
                        logger.info(
                            "wiki 카드 생성 스킵 (전사 없음/title_description): %s",
                            title,
                        )
```
**분기·로그 문구 모두 그대로 존재. 완화되지 않았다.**

## V5-3. pytest 봉인 확인

`tests/test_transcriber.py` 의 `class TestWhisper429ImmediateReject` (`:282`):

| 테스트 | 봉인 대상 |
|---|---|
| `test_429_returns_none` (:299) | 429 → None |
| `test_429_does_not_consume_forged_body` (:304) | **정상 포맷의 위조 본문**을 성공으로 승격하지 않음 |
| `test_429_no_retry` (:313) | `mock_post.call_count == 1` — 재시도 0회 |
| `test_429_logs_explicit_congestion_warning` (:319) | 429 를 일반 실패로 뭉개면 사라지는 경고 |
| `test_429_falls_through_to_title_description_failclosed` (:329) | 429 → title_description 전 경로 |

`tests/test_main_pipeline.py:159` — "전사가 없으면(title_description) wiki 카드는 만들지 않되…"
및 `:177` `assert not mock_generate_summary.called` 로 요약 호출 차단까지 봉인.

★ 특기: `test_429_does_not_consume_forged_body` 는 **상태코드만 429이고 본문은 성공 응답처럼
생긴 위조값**을 투입한다. 과거 피드백(`fail-closed 테스트를 malformed 입력만으로 짜면
정상 포맷의 위조값을 구조적으로 놓친다`)이 반영된 설계다.

## V5 판정 — **fail-closed 유지. 완화 없음.**

---

# V6. 클라이언트 동적 타임아웃 실측

`compute_whisper_timeout()` / `parse_duration_seconds()` 직접 호출 결과 (실제 출력):

```
input              parse_duration_seconds   compute_whisper_timeout 
----------------------------------------------------------------------
'PT2H20M35S'       8435.0                   5400.0                  
'PT0S'             0.0                      600.0                   
None               None                     600.0                   
'PT10M'            600.0                    750.0                   
'not-a-duration'   None                     600.0                   
'600'              600.0                    750.0                   
0                  0.0                      600.0                   
8435               8435.0                   5400.0                  
-5                 None                     600.0                   
''                 None                     600.0                   
'P1DT2H'           93600.0                  5400.0                  
True               None                     600.0                   
'PT30M'            1800.0                   1650.0                  
```
(`'not-a-duration'` 투입 시 `영상 길이 파싱 실패(무시하고 기본 타임아웃 사용)` 경고 출력 후 폴백 — 예외 미발생)

## 핵심 질문 답변

| 질문 | 실측 답 |
|---|---|
| `"PT2H20M35S"` → 몇 초? | `parse_duration_seconds` = **8435.0초**, `compute_whisper_timeout` = **5400.0초** |
| 사고 당시 전사 소요 2597초를 커버하는가? | **커버함.** 5400 > 2597, 여유 **2803초** |
| `"PT0S"` | **600.0초** (MIN) |
| `None` | **600.0초** (MIN) |
| 잘못된 문자열 `"not-a-duration"` | **600.0초** (MIN, 경고 로그 후 폴백, 예외 없음) |

## 클램프 동작 확인

```
상한 클램프: PT10H -> 5400.0 (MAX=5400)
하한 클램프: PT1M  -> 600.0 (MIN=600)
클램프 경계: raw=duration*0.75+300; 5400 도달 duration = 6800.0 초
```
- 상한: `PT10H`(36,000초) → raw = 27,300 → **5400 으로 클램프됨** ✔
- 하한: `PT1M`(60초) → raw = 345 → **600 으로 클램프됨** ✔
- 중간 영역 무클램프 통과: `PT30M`(1800초) → 1800×0.75+300 = **1650** ✔ (클램프 미적용)
- `True`(bool) 는 int 서브클래스임에도 명시적으로 배제되어 None → 600초 ✔
- 음수 `-5` → None → 600초 ✔

**상·하한 클램프 모두 실제로 동작한다.**

---

# V7. 회귀

## InsuWiki 파이프라인
```
$ cd /home/jay/projects/insuwiki/scripts/youtube-pipeline && python3 -m pytest tests/ -q
...
154 passed, 1 warning in 5.04s
```
(경고 1건은 `google.generativeai` 패키지 deprecation 안내로 본 수정과 무관)

## whisper-gpu
```
$ python3 -m pytest /home/jay/workspace/services/whisper-gpu/test_server.py -q
configfile: pyproject.toml
plugins: anyio-4.12.1, asyncio-1.3.0, cov-7.0.0, respx-0.22.0, Faker-40.8.0
asyncio: mode=Mode.STRICT, debug=False, asyncio_default_fixture_loop_scope=None, asyncio_default_test_loop_scope=function
collected 50 items

test_server.py ..................................................        [100%]

============================== 50 passed in 2.92s ==============================
```

**154 passed / 50 passed — 토르 보고와 일치. 회귀 0건.**

---

# V8. 정리

## GPU
```
utilization.gpu [%], memory.used [MiB]
0 %, 1957 MiB

pid, used_gpu_memory [MiB]
598093, 1932 MiB
```
**GPU 사용률 0% 복귀 확인.** 잔여 1957MiB 는 whisper-gpu 프로세스(598093)가 보유한 large-v3
모델이며 `unload_timeout_sec=600` 정책상 10분 미사용 시 자동 언로드된다(정상).

`/v1/health`: `{"status":"ok","device":"cuda","gpu_memory_used_mb":1957,"models":{"small":"unloaded","medium":"unloaded","large-v3":"loaded"},"last_used":1787667556.4804368,"unload_timeout_sec":600}`

## 임시 파일
```
-rw-rw-r-- 1 jay jay  42154598 Aug 25 20:43 /tmp/whisper_yt_EvmWgJ_THDw.webm
-rw-rw-r-- 1 jay jay 134296642 Aug 25 20:43 /tmp/whisper_yt_YdA_zlA0oUA.webm
```
★ 이 2개는 **20:43 생성 고아 파일**로 지시대로 **보존**했다(본 측정 산출물 아님).

- 본 측정이 만든 `/tmp/whisper_yt_*` 파일: **전량 서버가 자동 삭제**
  (`임시 파일 삭제 완료` 로그 4건 = V1-A, V2-A, V2-B, **V5 의 429 거절 경로**)
- `/tmp/whisper_upload_*` 잔여: **0건** (V3 4건 + V5 2건 전부 정리됨)
- ★ **429 거절 경로에서도 임시 파일이 정상 삭제됨**을 확인:
  `2026-08-25 23:18:55,456 [INFO] whisper-gpu: 임시 파일 삭제 완료: /tmp/whisper_yt_v6oVfFko04A.webm`
  (429 는 23:18:55.388) — `finally` 블록이 429 경로에서도 동작한다.
- 내 측정 스크립트·로그는 `/tmp/t3018p/` 에만 존재. 다운로드한 `sample.webm`(1.4MB)은 삭제 완료.

---

# ★ baseline ↔ post-fix 대조표 (종합)

| # | 항목 | 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건/회 | 2건/회 | **변화 없음** (의도된 미수정) |
| 4 | 콜드 스타트 부분 지연 | 0.784785 s | 0.784670 s | **변화 없음** (의도된 미수정) |
| 5 | 콜드 스타트 블로킹 구간 길이 | ≈9.24초 | ≈9.07초 | **변화 없음** |
| 6 | **2번째 요청 첫 핸들러 로그 지연** | **22.855초** | **0.006초** | **★ 해소 (약 3,800배)** |
| 7 | 2번째 요청 다운로드 완료 시점 | A 전사 완료 **+40ms** (블로킹) | **A 전사 도중** (23:14:54, A는 23:15:14 완료) | **★ 해소** |
| 8 | 큐 한도 초과 시 동작 | (기능 없음) 무한 대기 | **429 in 0.044~0.049초** + `Retry-After: 300` | **★ 신규 동작 확인** |
| 9 | YouTube 엔드포인트 429 전달 | (기능 없음) | **429 반환** (500 아님) | **★ 확인** |
| 10 | 최대 요청 wall time | 48.910초 | 53.966초 | 600초 미도달 (둘 다) |
| 11 | 600초 타임아웃 도달 | 0건 (짧은 영상 한정) | 0건 | **동일** |
| 12 | 클라이언트 타임아웃 (사고 영상) | 600초 고정 (2597초 전사 → **실패**) | **5400초** (2597초 커버, 여유 2803초) | **★ 해소** |
| 13 | fail-closed (429 → title_description) | (429 없음) | **실호출로 실증** | **★ 유지** |
| 14 | 회귀 (파이프라인 / whisper-gpu) | — | **154 passed / 50 passed** | **회귀 0건** |
| 15 | GPU 사용률 복귀 | 0% | 0% | **동일** |
| 16 | 임시 파일 정리 (정상 경로) | 정상 삭제 | 정상 삭제 | **동일** |
| 17 | 임시 파일 정리 (429 경로) | (해당 없음) | **정상 삭제 확인** | **★ 확인** |

---

# ★ 발견한 문제 · 한계 · 잔여 위험

## 잔여 위험 1 (중) — YouTube 경로의 429 는 **다운로드를 낭비한 뒤** 나온다

`run_transcription()` 의 큐 체크는 `server.py:446` 에 있는데, `/v1/youtube-transcribe` 는
**yt-dlp 다운로드(`:773-802`)를 모두 마친 뒤**(`:825`) `run_transcription()` 을 호출한다.

실측: V5 의 클라이언트 429 응답까지 **4.302초** 소요. 이 중 대부분이 yt-dlp 다운로드다
(`/v1/transcribe` 직접 경로의 429 는 0.044초).

영향:
- 거절될 요청이 **YouTube 대역폭·디스크 I/O·yt-dlp 프로세스를 100% 소모**한다.
- 사고 당시처럼 **2시간 20분짜리 영상**이면 다운로드만 수십 초~수 분이며, 그 전부가 버려진다.
- "즉시 거절"의 취지가 GPU 보호에는 부합하나 **다운로드 자원 보호에는 미치지 못한다.**

다만 GPU 는 정상 보호되고 임시 파일도 정리되므로(V8 확인) **기능적 결함은 아니다.**
개선한다면 다운로드 **이전**에 큐 depth 를 선체크하는 경로가 필요하다. — 오딘 판단 요청.

## 잔여 위험 2 (중) — 동적 타임아웃이 **큐 대기 시간을 고려하지 않는다**

`compute_whisper_timeout()` 은 **자기 영상 길이**만으로 타임아웃을 산정한다. 그런데
`WHISPER_MAX_QUEUE=2` 는 요청 1건이 **앞선 1건을 기다리는 것을 허용**한다
(V3 REQ1 실측: 대기 27초 + 전사 27초 = wall 53.966초).

실측 전사 속도(3회 측정): 3.25x ~ 3.38x 실시간 (본 측정 89.9초 오디오 → 26.56/26.98초 전사,
사고 실측 8435초 → 2597초). 3.3x 로 놓고 계산하면:

| 영상 길이 | timeout | 자기 전사 | 대기+전사 (최악) | 판정 |
|---:|---:|---:|---:|:---|
| 900초 | 975 | 273 | 545 | OK |
| 3,600초 | 3000 | 1091 | 2182 | OK |
| 6,800초 | 5400 | 2061 | 4121 | OK |
| **8,435초 (사고 영상)** | **5400** | **2556** | **5112** | **OK (여유 288초, 5.3%)** |
| 8,911초 | 5400 | 2700 | 5401 | **TIMEOUT** |
| 10,800초 (3시간) | 5400 | 3273 | 6545 | **TIMEOUT** |
| 14,400초 (4시간) | 5400 | 4364 | 8727 | **TIMEOUT** |

**약 2시간 28분(8,911초)을 넘는 영상이 다른 긴 영상 뒤에 큐잉되면 여전히 타임아웃한다.**
사고 영상(8,435초)은 여유 5.3% 로 **간신히** 통과하는 수준이다.

완화 요인: 타임아웃해도 fail-closed 로 `title_description` 에 떨어지므로 **데이터 오염은 없다**
(V5 확인). 즉 안전하게 실패하지만 **긴 영상의 전사는 여전히 실패할 수 있다.**
상한 `WHISPER_TIMEOUT_MAX_SEC`(5400)은 환경변수로 조정 가능하다. — 오딘 판단 요청.

## 잔여 위험 3 (하) — 콜드 스타트 9초 블로킹은 그대로 남아 있다

의도된 미수정 범위이나 **사실 자체는 남는다**: 모델이 언로드된 상태(600초 미사용)에서
첫 요청이 오면 약 **9초간 서버 전체가 사실상 무응답**이다(health 3초 타임아웃 2회 발생).
`unload_timeout_sec=600` 이라 **10분 유휴 후 첫 요청마다 재발**한다 — 드문 일이 아니다.
헬스체크 기반 감시나 로드밸런서가 있다면 이 9초를 장애로 오판할 수 있다. — 오딘 판단 요청.

## 한계 4 — 긴 영상 실전사 **미실증**

본 검증의 전사는 전부 75~90초 오디오다(GPU 장기 점유 금지 지침 준수).
- 사고 영상급(8,435초)의 **실제 전사 완주는 미실행**이다.
- V6 의 타임아웃 충분성은 **계산값 검증**이며, 실제 2,597초 전사를 재현한 것이 아니다.
- 잔여 위험 2 의 표도 **실측 배속(3.25~3.38x)에 기반한 추정**이며 긴 영상 실측이 아니다.

## 한계 5 — 미측정 항목

- `/v1/transcribe/url` 경로: **미측정.** 동일 `run_transcription` 을 경유하므로 동일 동작이
  예상되나 실측하지 않았다.
- `WHISPER_MAX_QUEUE` 환경변수 override: **미측정** (기본값 2 로만 시험).
- `_gpu_queue_depth` 카운터 **누수 여부**: 정상 경로·429 경로에서는 V3/V5 연속 실행으로
  간접 확인(측정 후에도 새 요청이 200 을 받음). 그러나 **전사 중 클라이언트 강제 절단·
  서버 예외 상황에서의 카운터 복원은 실측하지 않았다.** `finally` 블록(`:495-496`)이
  존재하는 것은 코드로 확인했다.
- 파이프라인 전체(`main.py`) 통합 실행: **의도적 미실행** (Gemini 키 무효 상태에서
  `yt_update_last_crawled()` 커서 전진에 의한 영상 영구 유실 위험 회피).

---

# 종합 판정

| 원인 | 수정 목표 | 판정 |
|---|---|---|
| **A. 이벤트 루프 블로킹** | 전사 중 서버 응답 유지 | **★ 해소** — GPU 디코드 구간 타임아웃 16건 → **0건** |
| **A·C. 2번째 요청 차단** | 즉시 접수 | **★ 해소** — 22.855초 → **0.006초** |
| **②. 무한 대기 큐** | 즉시 429 거절 | **★ 동작 확인** — 44~49ms 거절, `Retry-After: 300` |
| **3. 429 → 500 뭉갬** | 상태코드 보존 | **★ 확인** — YouTube 경로 실트래픽 429 반환 |
| **4. 고정 600초 타임아웃** | 길이 비례 동적 산정 | **★ 해소** — 사고 영상 5400초(2597초 커버) |
| **fail-closed** | 완화 금지 | **★ 유지** — 실호출 429 → `title_description` 실증 |
| **회귀** | 0건 | **★ 0건** — 154 passed / 50 passed |
| 콜드 스타트 블로킹 | (의도적 미수정) | **변화 없음** — 회귀 아님, 잔여 9초 |

**결론: 수정은 목표한 결함을 실측으로 해소했다.** 다만 위 잔여 위험 3건(다운로드 낭비형 429,
큐 대기 미고려 타임아웃, 콜드 스타트 9초)과 한계 2건(긴 영상 실전사 미실증, 미측정 경로)은
남아 있으며 오딘 판단이 필요하다.

---

# 제약 준수 확인

| 금지 항목 | 준수 여부 | 증거 |
|---|---|---|
| `insuwiki-youtube-pipeline.timer` 기동 금지 | **준수** | `systemctl --user is-active` → `inactive` (측정 전/후 확인) |
| 파이프라인 전체 수동 실행 금지 | **준수** | `main.py`·`run_pipeline.sh` 미실행. 클라이언트는 `transcriber.transcribe()` 컴포넌트 단위 1회 직접 호출만 |
| GPU 장기 점유 금지 | **준수** | 전사 총 9건, 전부 75~90초 오디오. GPU 실사용 누적 약 4분. 545초 영상 `MoJ7s4g9ZaM` 미사용 |
| `server.py`·`transcriber.py`·`main.py` 수정 금지 | **준수** | 읽기 전용 접근만(`sed -n`, `grep`). 편집 도구 미사용 |
| 20:43 고아 파일 2개 보존 | **준수** | `EvmWgJ_THDw.webm`, `YdA_zlA0oUA.webm` 그대로 존재 |
| 서비스 재시작 금지(추가 확인) | **준수** | `MainPID=598091`, `NRestarts=0`, `ActiveEnterTimestamp` 불변 |
| 코드 위치 | **준수** | 측정 스크립트 전량 `/tmp/t3018p/`, 보고서만 workspace |

# 원자료 위치

| 파일 | 내용 |
|---|---|
| `/tmp/t3018p/poll.log` | V1 health 폴링 38건 |
| `/tmp/t3018p/req.log` | V1 전사 요청 송수신 타임스탬프 |
| `/tmp/t3018p/v2.log` | V2 오버랩 시험 |
| `/tmp/t3018p/v3.log`, `/tmp/t3018p/v3_*.hdr` | V3 큐 한도 4건 동시 + 429 헤더 원문 |
| `/tmp/t3018p/v5.log`, `/tmp/t3018p/v5_client.py` | V5 실호출 fail-closed |
| `/tmp/t3018p/v1.sh`, `v2.sh`, `v3.sh`, `v5.sh` | 재현용 측정 스크립트 |
| `journalctl --user -u whisper-gpu.service --since "2026-08-25 23:11:31"` | 서버 원본 로그 |