LiveKit RPC 2초 response timeout — ACK pending 경고 발생 메커니즘 분석 메커니즘 확정 근본 원인 미확정 수정 미적용

마지막 업데이트 2026-09-12

작성일: 2026-09-01 사건일: 2026-08-27 이슈 ID: 미지정 범위: apps/web · livekit-client 2.19.2

결론

RPC response received before ack 문구는 PPI가 만든 오류가 아니라 LiveKit JavaScript SDK의 RpcClientManager가 출력한 경고다. PPI의 세션 로그 수집기가 SDK의 console.warn을 ctx: "CONSOLE"로 저장했다.

로그에서 이 경고가 약 2초 간격으로 반복된 직접 이유는 PPI가 Runtime RPC에 responseTimeout: 2000을 전달하기 때문이다. LiveKit SDK는 ACK를 최대 7초 기다리지만, 로컬 응답 Promise는 2초에 먼저 거절될 수 있다. Promise의 finally가 실행될 때 ACK가 아직 pending이면 SDK가 위 경고를 남기고 ACK 타이머를 제거한다.

판정 경계: 확인된 것은 타임아웃 종료 순서의 역전이다. 네트워크에서 실제 RPC Response 패킷이 ACK보다 먼저 도착했다는 증거는 없다. 또한 요청이 Agent에 도달하지 않았는지, ACK가 지연됐는지, Agent 응답이 늦었는지는 브라우저 로그만으로 확정할 수 없다.

1. 분석 범위와 실행 경로

분석 대상은 lesson-log-20260827.jsonl.gz 한 건이다. 파일명과 달리 실제 형식은 gzip이 아닌 평문 JSONL이며 정상적으로 읽을 수 있었다.

PPI input policy / runtime control
  → apps/web/lib/voice-agent/livekit-client-session.ts
  → room.localParticipant.performRpc({ responseTimeout: 2000 })
  → livekit-client 2.19.2 / RpcClientManager.performRpc()
  → LiveKit reliable data transport
  → remote Agent RPC handler
  → ACK / response

SDK console.warn(...)
  → apps/web/lib/lesson-log-sink.ts
  → ctx: "CONSOLE" 세션 로그

구간	확인한 위치	역할
PPI RPC 호출	`apps/web/lib/voice-agent/livekit-client-session.ts:932-942`	모든 Runtime RPC에 2초 응답 제한 적용
입력 상태 RPC	`apps/web/lib/voice-agent/livekit-client-session.ts:1048-1067`	`ppi.set_input_enabled` payload 전송
콘솔 수집	`apps/web/lib/lesson-log-sink.ts:29-47`	외부 라이브러리의 warn/error를 lesson log로 저장
SDK 버전	`apps/web/package.json:51`	`livekit-client 2.19.2` 선언

2. 로그에서 확인된 사실

14,603전체 로그 항목

17해당 SDK 경고

2브라우저 세션/인스턴스

13/152.004~2.016초 인접 간격

세션	건수	인접 간격
세션 A	10	`2013, 2006, 2004, 2010, 23979, 2006, 2008, 2007, 2016ms`
세션 B	7	`2011, 2006, 2395, 2008, 2013, 2006ms`

17건의 부가 데이터는 모두 달랐다. 하나의 경고가 재출력된 것이 아니라 서로 다른 RPC 요청이 종료된 패턴이다.
Response timeout을 포함한 상위 오류 로그는 50건이었다. 하나의 실패가 여러 계층에서 기록되므로 고유 RPC 수와 동일한 값은 아니다.
세션 내 인접 간격 15개 중 13개가 2초 타이머 오버헤드 범위인 2004~2016ms에 모였다.
2395ms와 23979ms 공백도 있어 전체 17건이 끊김 없이 정확히 2초 주기인 것은 아니다.

3. 세 타이머의 의미

값	적용 주체	의미
2,000ms	PPI 호출자	브라우저가 응답 Promise를 기다리는 로컬 제한
7,000ms	LiveKit SDK	요청 도달과 ACK 왕복에 허용하는 최대 시간
8,000ms	LiveKit SDK → 상대	`maxRoundTripLatencyMs + 1000`으로 계산된 최소 유효 처리 제한

8초는 PPI 호출자가 반드시 설정해야 하는 최소값이 아니다. SDK는 responseTimeoutMs와 상대에게 전달하는 effectiveTimeoutMs를 별도로 관리한다. 공식 v2.19.2 테스트도 50ms 응답 타임아웃이 7초 ACK 타임아웃보다 먼저 끝나는 경우를 명시적으로 검증한다.

따라서 PPI의 2초 설정은 API 규약상 유효하다. 다만 상대에는 최소 8초가 전달되는데 호출자는 2초 만에 포기하므로, 이 사건처럼 원인 분류가 흐려지고 늦게 도착한 ACK/응답이 이미 정리된 요청으로 취급될 가능성이 생긴다.

4. 시간순 발생 메커니즘

0초

PPI가 RPC를 발행한다. SDK는 pendingAcks와 pendingResponses를 등록하고 ACK 7초 타이머를 시작한다. 상대에게 전달되는 처리 제한은 최소 8초다.

2초

PPI가 지정한 로컬 responseTimeout이 먼저 만료되어 RESPONSE_TIMEOUT으로 Promise가 거절된다.

2초+

completionFuture.promise.finally()가 실행된다. ACK가 여전히 pending이면 RPC response received before ack를 출력하고 ACK 상태와 7초 타이머를 제거한다.

7초

앞 단계에서 ACK 타이머가 제거됐으므로 원래 예정된 CONNECTION_TIMEOUT 경로는 실행되지 않는다.

경고 문자열은 “response를 실제 수신했다”는 뜻처럼 보이지만, 이 구현에서는 Promise가 성공·실패·타임아웃 중 어떤 이유로든 종료될 때 finally가 실행된다. 따라서 RESPONSE_TIMEOUT에서도 같은 경고가 나올 수 있다.

5. 가설 판정

가설	판정	근거
PPI 코드가 해당 경고를 직접 생성했다	기각	문구는 LiveKit SDK v2.19.2의 `RpcClientManager`에 존재하며 PPI에서는 일치 문자열이 없다.
2초 로컬 타임아웃이 ACK pending 경고를 촉발했다	유력	17건 중 대부분이 약 2초 간격이고, 같은 시각대에 `Response timeout` 상위 오류가 동반된다.
네트워크에서 Response 패킷이 ACK보다 먼저 도착했다	미확정	브라우저 로그에 요청별 ACK·응답 수신 시각이 없고, 경고가 실제 response 수신 없이도 발생한다.
Agent 또는 전송 구간이 ACK/응답을 누락·지연했다	미확정	동일 request ID를 가진 Agent 수신·처리 로그가 제공되지 않았다.

6. 변경 상태와 목표 동작

애플리케이션 변경은 없다. 이 문서는 로그와 코드 대조 결과를 기록한 분석 문서이며, timeout 변경·SDK 패치·추가 로깅은 아직 구현하거나 검증하지 않았다.

현재 동작	목표 동작
모든 Runtime RPC가 2초 제한을 공유하고, 2초 종료 시 SDK 경고가 실제 패킷 역전처럼 보인다.	RPC 종류별 실제 지연 분포에 맞는 제한을 사용하고 연결 실패와 응답 지연을 구분한다.
브라우저 로그만으로 요청 도달·ACK·Handler 실행·응답 경계를 나눌 수 없다.	request ID 기준으로 브라우저와 Agent의 전 구간 타임스탬프를 연결한다.
입력 ON/OFF처럼 연속되는 상태 변경 RPC가 늦게 처리될 때 최종 상태 일관성을 확인할 수 없다.	지연·중복·늦은 응답에서도 마지막 desired state와 Agent 상태가 일치함을 검증한다.

7. 검증한 방법

로그 형식과 빈도

file lesson-log-20260827.jsonl.gz
jq -s '[.[] | select(.msg=="RPC response received before ack")] | length' "$LOG"
jq -s '... group_by([.sessionId,.instanceId]) ... 인접 ts 차이 ...' "$LOG"
jq -s '[.[] | select(.msg=="RPC response received before ack") | .data]
       | {count:length, unique_data_count:(unique|length)}' "$LOG"

코드 대조

PPI의 performRpc 호출과 2초 설정을 현재 저장소 소스로 확인했다.
PPI의 콘솔 수집기가 외부 라이브러리 로그를 ctx: "CONSOLE"로 저장하는 것을 확인했다.
LiveKit 공식 GitHub의 client-sdk-js v2.19.2 태그에서 7초 ACK 타이머, 8초 최소 유효 처리 제한, 경고 발생 조건을 확인했다.
공식 SDK 테스트에서 짧은 응답 제한이 허용되는 경로를 확인했다.

8. 다음 판별과 제안

먼저 판별: request ID별로 브라우저 발행, Agent 수신, ACK 발행, Handler 시작·종료, 응답 수신 시각을 한 축에 기록한다.
지연 분포 수집: 정상·혼잡·재연결 상태에서 RPC 종류별 p50/p95/p99를 측정한다.
timeout 결정: LiveKit 문서 원칙대로 사용 사례를 만족하는 가장 짧은 값을 선택한다. ACK 생명주기와 정렬하는 8초 또는 초기 관찰값 10초는 제안일 뿐 승인된 요구사항이 아니다.
상태 일관성: 입력 ON/OFF가 연속 호출되거나 이전 요청이 늦게 처리돼도 마지막 요청이 최종 상태를 결정하는지 검증한다.
경고 분류: SDK 경고만 숨기지 말고, timeout 원인과 늦게 도착한 ACK/응답을 별도로 관측할 수 있게 한다.

timeout을 늘리는 것만으로 ACK 누락이나 Agent 처리 실패의 근본 원인이 해결되지는 않는다.

9. 남은 위험과 제한

Agent 로그가 없어 실패 경계는 브라우저의 로컬 timeout까지에서 멈춘다.
현재 50개의 상위 오류 로그는 고유 RPC 건수가 아니라 중복 계층 로그를 포함한다.
공식 소스는 PPI의 버전 선언과 동일한 GitHub 태그를 대조한 것이며, 로컬 pnpm store·node_modules 산출물을 직접 검사하지 않았다.
SDK 버전 변경 시 기본 timeout과 내부 구현이 달라질 수 있으므로 업그레이드 시 재검증이 필요하다.

10. 참고 자료

LiveKit client-sdk-js v2.19.2 — RpcClientManager.ts
LiveKit client-sdk-js v2.19.2 — RpcClientManager.test.ts
LiveKit 공식 문서 — Remote procedure calls
PPI 코드: apps/web/lib/voice-agent/livekit-client-session.ts
PPI 코드: apps/web/lib/lesson-log-sink.ts
분석 자료: lesson-log-20260827.jsonl.gz