마지막 업데이트 2026-09-30
결론: LiveKit agent 서버측 원인. 아동측은 배제. 아동 turn-5 발화의 STT 중간 전사(interim)는 57자까지 도착했지만 커밋 후 2.5초 기한 안에 final 전사를 받지 못해 agent가 정확히 2.50초에 이 턴을 폐기했다. 그 뒤에 final이 늦게라도 왔는지는 로그로 알 수 없다(아래 5절 정정). 응답 자체가 생성되지 않아 재생할 오디오도 없었고, 아바타는 idle 상태에 머물렀다.
신고 문장 "오 진짜? 그 로봇은 뭐 하는 로봇이었는데?"는 아동 발화가 아니라 AI 응답(response-5)이며 정상 재생됐다. 무응답은 그다음 아동 대답(turn-5)에 대한 것이다.
이슈 분류기(ppi-issue-classifier)는 child 59%로 판정했다. 분류기 입력(guest·monitor·LiveKit 서버·socket)에 agent CloudWatch 로그가 없었고, child 쪽 점수는 20분 구간 전체의 문제 턴과 무관한 신호(guest_voice_event_ignored 75건=unsupported_event 상시 로그, Audio output suspected silent는 19:00:31로 4분 전, 자동전환·DECODE_OVERLOAD는 창 밖)에서 나왔다.
19:04:55 AI response-5 "오 진짜? 그 로봇은…" 재생
→ SFU active speaker remote=true, 아동 audio element paused:false·currentTime 증가 정상
19:04:48~19:05:00 아동 turn-5 발화 (약 12초, 중간에 두 번 끊겼다 재개 = endpointing_resumed ×2)
→ agent VAD speaking 이벤트 수신 = 아동 마이크 업링크 정상
19:05:03.605 user_turn_committed (turn-5, user_silence_endpointing_timer 2400ms)
19:05:04.203~04.652 user_stt_event_received interim, 길이 1 → 57 (음성은 STT에 도달)
✗ 기한(19:05:06.105) 안에 turn-5 final 미확보
19:05:06.107 WARNING skipping Half Cascade turn without exact provider final
(failure_category=provider_final_not_admitted, 커밋 +2.50초 = 타임아웃 값)
→ 응답 생성 없이 return → AI 무응답 · 아바타 idle 유지
19:05:16.205 user_state_changed → away (13초 무반응)
19:05:19.5 진행자 텍스트 전송 → 19:05:20.516 agent_response_started response-6 (회복)
대조군: 같은 수업의 다른 8개 턴은 커밋 후 0.76~1.5초 안에 final(user_stt_segment)이 도착했다. 19:00~19:20 전체에서 턴 폐기는 이 1건뿐.
턴 커밋 뒤 realtime 입력 전사의 정확한 provider final을 최대 2.5초 기다린다. final이 없으면 fail-closed로 턴을 버린다. 부정확한 입력으로 대답하지 않으려는 설계지만, 이번처럼 기한 안에 final을 못 받으면 아동 입장에서는 "말했는데 대답 없음"이 되고 클라이언트·모니터에 아무 신호도 가지 않는다.
| 파일 · 줄 | 내용 |
|---|---|
| ~/Downloads/ppi-livekit-agent-20260929_1904-1906.log :440 / :475 | turn-4 커밋 → final 1.5초 (정상 대조군) |
| 동 :568 | turn-5 speaking (음성 도달) |
| 동 :613 | turn-5 user_turn_committed 19:05:03.605 |
| 동 :616~725 | interim 길이 1→57, 기한 내 final 미확보 |
| 동 :730 | skipping Half Cascade turn … provider_final_not_admitted 19:05:06.107 |
| 동 :731 / :734 | away 19:05:16 / response-6 시작 19:05:20 |
| ~/Downloads/ppi-livekit-agent-20260929_1900-1920.log | 수업 전체 커밋·final 대조, 폐기 1건 |
| ppi-issue-classifier/inputs/20260929_이현우_18/session-20260929.jsonl.gz (압축 해제 기준) :2559 / :2583 / :2591 / :2783 | response-5 텍스트 / remoteSpeaking true / audio element 정상 재생 / 진행자 텍스트 전송 (아동 시계) |
agent 로그는 CloudWatch /ppi/livekit/prod/agent, job AJ_X2z9UJp3JUJQ에서 ppicw logs --start "9/29 19:04" --end "9/29 19:06" --job AJ_X2z9UJp3JUJQ로 받았다.
skipping Half Cascade turn without exact provider final은 "이 턴에 쓸 정확한 provider final을 허용하지 못해 버림"이라는 공통 결과 로그다. 원인 경로는 여러 개이고, 일부는 별도 경고를 남긴다.
| 원인 경로 | 별도 경고 | 이번 건 |
|---|---|---|
| commit 응답(item_id) 지연·실패 | commit acknowledgement timed out/failed | 0건 |
| 전사 복구 중 예외 | transcription recovery failed | 0건 |
| OpenAI 전사 실패 이벤트 | failed to transcribe input audio ERROR (realtime_model.py:2492) | 0건 |
| provider error / 연결 오류 | returned an error | 0건 |
| 2.5초 기한 초과 | 없음 (기한 확인 후 조용히 return, agent_activity.py:3536 부근) | 해당 (커밋 +2.502초) |
| 빈 final / 다른 item_id | 없음 | 구분 불가 |
함정: interim 스냅샷이 있어도 realtime native final missing; rejecting exact-item interim 경고가 안 찍힌다. wait_for_input_transcription()(realtime_model.py:2535)은 타임아웃이 나도 스냅샷을 돌려주지만, 호출부가 interim 검사 전에 기한을 먼저 확인하고 return하기 때문이다.
폐기 경고에는 turn_id/item_id 필드가 없다. ① 당시 대기 중인 턴이 turn-5뿐(turn-4는 19:04:42 판정 완료, :613~:730 사이 다른 커밋·drop 없음) ② 커밋 +2.502초 = 기한 ③ 수업 전체에서 final이 빠진 턴이 turn-5뿐 ④ response-6의 source_user_turn_id가 turn-5 — 네 가지 배타성으로 귀속했다.
정정: 초판에서 "final이 끝내 오지 않았다"고 썼으나 과장이었다. Half Cascade에서는 final이 도착 즉시 로그되지 않고 허용 판정을 통과해야 user_stt_event_received is_final:true로 기록된다(agent_activity.py:2714 defer_half_cascade_admission). 턴 폐기 후 늦게 온 final은 record_realtime_final()이 None이라 로그 없이 버려진다(:2708). 확정 가능한 범위는 "2.5초 안에 받지 못했다"까지다.
이 수업만의 일이 아니다. 같은 폐기 경고가 일주일간 145건, 약 130개 방에서 났고, 방당 대부분 1건(최대 2건)이다. OpenAI 전사 실패 알림(failed to transcribe input audio)은 일주일 내내 0건이다.
| 날짜 | 턴 폐기 | 방 수 | 수업 종료 시 flush 타임아웃 | 시간대 |
|---|---|---|---|---|
| 9/23 (화) | 28 | 26 | 2 | 11~21시, 19~21시 18건 |
| 9/24 (수) | 0 | 0 | 0 | — |
| 9/25 (목) | 0 | 0 | 0 | — |
| 9/26 (금) | 2 | 1 | 0 | 15시 |
| 9/27 (토) | 10 | 9 | 0 | 09~17시 |
| 9/28 (일) | 21 | 18 | 2 | 19시 8건 · 21시 6건 |
| 9/29 (월) | 82 | 79 | 3 | 17~20시 69건, 19시 30건 |
| 9/30 (~14:10) | 2 | 1 | 0 | 14시 |
판별법: AI 무응답 신고에서 agent 로그에 provider_final_not_admitted가 커밋 +2.5초에 찍히고, 그 사이 commit 응답·전사 실패·provider error 경고가 없으면 이 메커니즘(기한 초과)으로 확정한다. user_turn_dropped·캐시 오염(빈 전사 캐시 키 문서)과는 다른 경로다 — 이번 건은 훅 트레이스 자체가 없다.