마지막 업데이트 2026-10-07
최종 세션 실패 17건(로그 확정) + 1건(로그 유실, 서버 로그로 추정) = 18건, 아동 13명. AI 스텝 시작이 자동 재시도 1회까지 실패해 포기된 건수다. 배정 실패한 시도는 130건이었고, 그중 87%는 재시도나 다음 시작으로 회복됐다.
원인: 18시·19시 정각 수업 시작으로 AI job 수요가 슬롯 상한에 닿았다(19시: 아동 36명 vs 슬롯 34개 = 태스크 17대 × 워커당 2). 워커가 새 job을 받을지는 job 수로 정해지는데, 오토스케일은 CPU 평균에 반응하는 것으로 보인다. 슬롯이 다 차도 CPU 평균은 40%대라 증설 결정이 13~14분 늦었다(18:16, 19:17). 태스크 기동 자체는 2분이었다.
8/25 사건과의 차이: 8/25는 LiveKit 노드 하나에 워커가 쏠린 "노드 단위 포화"였다. 10/6은 주요 노드 3개가 같은 워커 23대를 공유했고 실패도 고르게 퍼져 있어(41/26/27) 풀 전체 포화다. 좀비 job(1시간 초과)은 0개, CPU 최대치는 87%로 CPU 포화도 없었다.
// 19시 구간 (KST). 18시도 같은 패턴: 18:03 첫 실패 → 18:16 증설 결정 → 18:18 반영 → 실패 종료 18:16 CPU 평균 35~39%가 13분 지속 → DesiredTaskCount 12 → 17 (슬롯 34) 18:35 18:30 수업 job 20개 → 17대로 버팀 (실패 1건) 19:00 정각 수업 동시 시작 (아동 36명, 그룹 12개 포함) → 동시 job 0 → 32 (19:04) 19:03 워커 17대 중 15대 "worker is at full capacity" (load 0.99 = 2/2 × 0.99) 19:02~19:18 방 생성 순간 빈 슬롯이 없으면 no workers with sufficient capacity → 그 방은 끝까지 미배정 → 클라이언트 10초 readiness timeout → 재시도 1회 (새 방) → 재시도도 지면 Failed to start session (handler) = 최종 실패 19:13 워커 17/17 전원 만석, 동시 job 34/34 19:05~19:16 슬롯 사용률 94~100% / CPU 평균 41~47% ← 오토스케일이 보는 값은 여유 19:17 DesiredTaskCount 17 → 23 (pending 6) 19:18 worker registered ×6 (19:18:08~19:18:20) 19:19 RunningTaskCount 23 (슬롯 46) → 이후 배정 실패 0건
| 아동 | 회차 | 건수 | 시각 | 진행자 기록 |
|---|---|---|---|---|
| 김단 | 31 | 3 | 19:10, 19:11, 19:15 | 스텝 전환 후 동작 없음, 강제퇴장 |
| 백찬혁 | 44 | 2 | 19:08, 19:14* | no message yet, 강제퇴장 2회, 수업 중단 |
| 김하준 | 1 | 2 | 19:14, 19:18 | 대화시작 안 나와 이전 활동 갔다 복귀 |
| 박하연 | 14 | 2 | 19:07, 19:16 | - |
| 정유건 | 14 | 1 | 18:15 | 티키 멘트 시작 안 됨 |
| 김가빈 | 61 | 1 | 19:13 | 세션 자동/수동 실행 안 됨 |
| 백선우 | 16 | 1 | 19:11 | 미배정 뒤 19:12 재배정 복구 |
| 손경훈 | 34 | 1 | 19:07 | - |
| 박주안 | 10 | 1 | 19:09 | - |
| 김도현** | 21 | 1 | 19:09 | - |
| 김권후 | 6 | 1 | 19:13 | - |
| 김재율 | 6 | 1 | 19:17 | - |
| 안지훈 | 20 | 1 | 19:17*** | - |
* 재시도 예약(19:14:34) 직후 세션 로그가 끊겨 handler 로그 없음. 서버 로그에서 재시도 방도 no workers with sufficient capacity로 실패하고 19:14:46 퇴장 확인 → 추정 1건. ** 21회차 후보가 2명(ddab728c, cd1cf2ef)이라 매칭 미확정, 최종 실패는 cd1cf2ef. *** 세션 로그에는 19:20:14로 찍혔지만 아동 단말 시계가 3분 빨랐다(서버 로그상 두 방 실패 19:16:51·19:17:03, 퇴장 19:17:14). 표의 시각은 모두 서버 시각 기준으로 맞췄다.
배정 실패한 시도 130 (세션 로그 129 + 로그 미수집 1)
├ 41 영상 스텝 중 미리 시작(prepare) 실패 → AI 스텝에서 다시 시작 (지연만)
├ 69 AI 스텝 1차 실패 → 자동 재시도
│ ├ 51 재시도 성공 (약 11초 지연)
│ ├ 17 재시도도 실패 → 최종 실패
│ └ 1 백찬혁 19:14 (로그 유실, 서버 로그로 최종 실패 추정)
├ 17 위 재시도 시도 자체의 실패
└ 2 새 요청으로 교체(superseded) → 이어서 성공
세션 시도(방) 1,193 / 배정 실패 130 (10.9%) / 실패 겪은 아동 46 / 123명
30분 구간: 18:00 시도 272 실패 27 · 18:30 190/1 · 19:00 446/102 · 19:30 285/0
| 위치 | 동작 |
|---|---|
apps/livekit-agent/agent.py:367 _ppi_agent_load | load = active_jobs / PPI_AGENT_MAX_JOBS_PER_WORKER(2) × 0.99, threshold 0.99. CPU 실측은 load에 들어가지 않는다 → job 2개면 무조건 만석 |
LiveKit 서버 agentservice.go | 방 생성 시 job 배정을 1회 시도. 후보가 바닥나면 no worker available to handle job으로 폐기, 나중에 슬롯이 비어도 그 방에는 다시 배정하지 않는다(실패 방 104개 중 이후 배정 0) |
apps/web/lib/voice-agent/livekit-client-session.ts:80 | LIVEKIT_AGENT_READY_TIMEOUT_MS = 10000 — agent 대기 10초 |
apps/web/lib/voice-agent/livekit-readiness-retry.ts:1 | READINESS_RETRY_MAX_ATTEMPTS = 1, 대기 300~1200ms. readiness timeout일 때만 새 방으로 재시도 → 최악 약 21초 |
apps/web/entities/guest-session/model/use-ai-session.ts:2926 handleStartSession | 재시도 소진 시 readiness_retry_exhausted → Failed to start session (handler) + alert("세션 시작에 실패했습니다.")(:2991). 이후 그 스텝은 진행자 수동 시작이나 스텝 이동 전까지 재시도하지 않는다 |
| 영상 스텝 prepare 경로 | 재시도 없이 AI session prepare failed로 끝나고, AI 스텝 진입 시 위 정식 시작을 다시 한다 |
| 시각 | Desired | Pending | Running | CPU 평균 | 의미 |
|---|---|---|---|---|---|
| 18:03~18:15 | 12 | 0 | 12 | 34~39% | 만석 워커 9~11/12인데 결정 없음 |
| 18:16 | 17 | 0 | 12 | 35.7% | 증설 결정 |
| 18:18 | 17 | 0 | 17 | 2분 뒤 기동 | |
| 19:03~19:16 | 17 | 0 | 17 | 41~47% | 만석 워커 14~17/17인데 결정 없음 |
| 19:17 | 23 | 6 | 17 | 43.8% | 증설 결정 |
| 19:19 | 23 | 0 | 23 | 2분 뒤 기동 |
job 1개 ≈ 태스크 CPU 22%(19:13 job 34 / 태스크 17 / CPU 평균 45%). 그래서 슬롯이 다 차도 CPU 평균은 50%를 넘기 어렵다. CPU 기준 정책은 만석을 "여유 있음"으로 본다.
AWS 기본 target tracking이면 보통 3분 안에 반응한다. 13~14분은 평가 기간이 긴 알람이나 step scaling일 가능성이 있다(추정, 정책 원문 미확인).
| 19시 아동 | 19시 직전 슬롯 | 19:00~19:20 배정 실패 | |
|---|---|---|---|
| 9/29 (화) | 약 32명 | 40 (20대) | 0건 |
| 10/6 (화) | 36명 (그룹 12개 포함) | 34 (17대) | 70건 |
수요가 슬롯보다 적으면 실패가 없었다. 19시 직전 태스크 수는 그 전 시간대 CPU로 결정돼, 수업 일정과 무관하게 운에 따라 모자랄 수 있다. 그룹 수업도 아동마다 AI 방을 따로 쓴다.
| 가설 | 판정 | 근거 |
|---|---|---|
| 좀비 job 슬롯 점유 (9/15형) | 기각 | 1시간 넘게 산 job 0개 (job 1,433개 시작·종료 전수 대조) |
| CPU 포화 | 기각 | 단일 태스크 최대 87%, VAD inference is slower than realtime 27건(최대 2.4초), 백찬혁 방 0건 |
| 노드 단위 포화 (8/25형) | 기각 | 주요 노드 3개 모두 같은 워커 23대에 배정, 실패 41/26/27로 고르게 분포 |
| 사후 점유 20초 (8/25 기여 요인) | 해당 없음 | PR #1027의 requesting job shutdown after session close가 prod에 찍힘 → 이미 반영 |
| agent 프로세스 기동 지연 | 기각 | process initialized 중앙값 0.5초, 최대 3.8초 |
| 아동 단말 문제 | 기각 | 실패 방은 agent에 job 요청 자체가 도착하지 않음(서버 배정 단계) |
not dispatching agent job since no worker is available은 JT_PUBLISHER 타입이라 정상 방에서도 매번 찍힌다. 판별자로 쓰면 안 된다. 진짜 신호는 JT_ROOM의 no worker available to handle job이다. failed to assign job to worker(124줄)도 방 115개 중 32개는 다른 워커로 재시도해 성공했으므로 실패 건수로 세면 안 된다.relayLiveKitDiagnosticToSocket처럼 소켓으로 보내면 서버에서 바로 집계할 수 있다./ppi/livekit/prod/agent의 worker is at full capacity / below capacity를 @logStream(워커)별 마지막 상태로 이어 붙인다. ppicw logs 출력에는 logStream이 빠지므로 ds_query로 직접 질의한다.received job request(시작) ~ process exiting(종료).DesiredTaskCount·PendingTaskCount·RunningTaskCount 1분 값. 결정과 기동을 분리해서 본다.service_name="ppi-livekit"의 selected node for room + assigned job to worker / no worker available to handle job.Failed to start session (handler). 세션 로그의 ts는 아동 단말 시계라 어긋날 수 있다(이번에 1명 +3분) — 시각은 서버 로그와 대조해 확정한다. 서버 로그만으로는 재시도 성공과 최종 실패를 구분할 수 없다(서버 로그만으로 센 초기 추정 56건은 prepare 실패를 섞어 부풀린 값이었다).ppi-livekit-prod-agent의 Auto Scaling 탭에서 확인해야 확정된다. 이윤건(20:10 실패)은 로그 범위 밖이라 확인하지 않았다.