오디오 체인 health 로그에 렌더 결손 ratio 추가

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

23bf0e7d charles-na · 2026-09-18 Feature (로깅 전용) 2 files +145 −0 PR #1117

아동 단말에서 mic-audio·ai-audio 양쪽에 “지지직”이 날 때 1차 판별자였던 오디오 클럭 전진 비율(ratio)을 세션로그 한 줄에서 바로 읽을 수 있게 한다. 지금까지는 Audio chain health 인접 두 줄의 currentTime을 사후에 빼야만 알 수 있어, 9/17 세션은 LogRocket 내보내기가 결손 시작 43초 전에서 잘려 “정상”으로 오판할 뻔했다. 리뷰 시 가장 먼저 볼 지점은 trackRenderDeficit이 공유 AudioContext 폐기 경로를 건드리지 않는지(WARN 전용)와, 벽시계로 Date.now()를 쓴 선택이다.

무엇이, 왜 바뀌었나

AudioContext.currentTime은 렌더 스레드가 실제로 그린 128샘플 블록 수 ÷ 48000이다. 하드웨어가 샘플을 가져가는 속도를 렌더가 못 따라가면 그 블록은 무음으로 대체되고 currentTime에 반영되지 않는다. 그래서 5초 창에서 Δ currentTime ÷ Δ 벽시계가 1보다 작으면 그 차이만큼 소리에 구멍이 났다는 뜻이다. 홍윤우 1회기(8/31)·원준호 47회기(8/27)·9/17 사례 세 건 모두 이 값으로 단말 렌더 결손을 확진했고, 네트워크 원인은 매번 기각됐다.

영향 범위: 게스트(아동) 페이지의 LiveKit 입력 오디오 체인(LiveKitAudioChainProcessor)만. 5초 주기 health 로그에 필드 3개가 늘고 WARN 한 종류가 추가된다. 동작 변경은 없다.
재사용한 패턴: 기존 Audio chain not rendering(완전 정지) 판정과 같은 setInterval 안에서 계산하고, 연속 관측 카운터(nonRenderingHealthChecks)와 같은 꼴의 renderDeficitChecks를 둔다.
임계값: RENDER_DEFICIT_RATIO = 0.98, RENDER_DEFICIT_WARN_CHECKS = 2. 정상 세션 관측치(0.998~1.000, 단발 최저 0.976)와 결손 세션(0.92~0.97 지속)을 가르는 값으로, 홍윤우 문서의 판별법을 그대로 코드로 옮겼다.

코드로 보는 핵심 지점

1. health 체크마다 벽시계·오디오클럭 차분과 ratio를 같이 남긴다

      apps/web/lib/voice-agent/livekit-audio-chain-processor.ts — startHealthLogging()
          this.healthInterval = setInterval(() => {
            const currentTime = audioContext.currentTime;
            const now = Date.now();
            const currentTimeAdvanced = currentTime > this.lastHealthContextTime;
            const wallDeltaMs = now - this.lastHealthWallTime;
            const contextDeltaMs = Math.round(
              (currentTime - this.lastHealthContextTime) * 1000,
            );
            const renderRatio =
              wallDeltaMs > 0
                ? Number((contextDeltaMs / wallDeltaMs).toFixed(3))
                : null;
            this.lastHealthContextTime = currentTime;
            this.lastHealthWallTime = now;
            const data = {
              state: audioContext.state,
              currentTime: Number(currentTime.toFixed(3)),
              currentTimeAdvanced,
              wallDeltaMs,
              contextDeltaMs,
              renderRatio,
    

첫 체크의 기준점은 startHealthLogging 진입 시각·currentTime이다. 그래프 재구성(graph built)마다 기준점이 리셋되므로, 사후 스캔에서 경계를 건너 차분하던 함정이 코드 안에서는 생기지 않는다.

2. 결손은 로그로만 — 폐기 경로와 분리

      apps/web/lib/voice-agent/livekit-audio-chain-processor.ts
            } else {
              this.nonRenderingHealthChecks = 0;
              logger.info("Audio chain health", data);
              this.trackRenderDeficit(renderRatio, data);
            }
          }, HEALTH_LOG_INTERVAL_MS);
        }
      
        private trackRenderDeficit(renderRatio: number | null, data: Record<string, unknown>): void {
          if (renderRatio === null || renderRatio >= RENDER_DEFICIT_RATIO) {
            this.renderDeficitChecks = 0;
            return;
          }
          this.renderDeficitChecks += 1;
          if (this.renderDeficitChecks >= RENDER_DEFICIT_WARN_CHECKS) {
            logger.warn("Audio chain render deficit", {
              ...data,
              consecutiveDeficitChecks: this.renderDeficitChecks,
            });
          }
        }
    

trackRenderDeficit은 markSharedContextUnhealthy를 호출하지 않는다. 결손 세션에서도 마이크 그래프는 살아 있으므로(홍윤우·9/17 모두 state:running, 전사 정상) ctx를 폐기하면 오히려 세션이 끊긴다. 폐기는 기존 not rendering(currentTime 완전 정지 3회) 경로만 맡는다.

3. 테스트 — 벽시계와 오디오클럭을 따로 전진시켜 ratio·WARN·폐기 없음을 고정

      apps/web/lib/voice-agent/livekit-audio-chain-processor.test.ts
      const advance = (wallMs: number, contextSec: number) => {
        fakeWallMs += wallMs;
        deficitContext.currentTime += contextSec;
        runDeficitCheck();
      };
      advance(5000, 5);      // 정상
      advance(5000, 4.781);  // 결손 1회 (0.956)
      advance(5000, 4.72);   // 결손 2회 연속 → WARN
      advance(5000, 5);      // 회복
      ...
      assert.deepEqual(healthLines.map((l) => l.data.renderRatio), [1, 0.956, 0.944, 1]);
      assert.equal(deficitWarns.length, 1);
      assert.equal(deficitWarns[0]?.data.consecutiveDeficitChecks, 2);
      assert.equal(deficitReleases[0]?.discardReason, undefined);
    

4.781초는 9/17 세션 첫 결손 창(17:14:09 → 17:14:14)의 실측값이다. 로그는 서버 모드 JSON 라인을 console.log/console.warn에서 가로채 파싱한다.

레이어별 변경 요약

레이어	파일	핵심 변경
게스트 오디오 체인	`apps/web/lib/voice-agent/livekit-audio-chain-processor.ts`	health 로그에 `wallDeltaMs`·`contextDeltaMs`·`renderRatio` 추가, `trackRenderDeficit`로 연속 2회 결손 시 `Audio chain render deficit` WARN. 상수 2개, 필드 2개(`lastHealthWallTime`, `renderDeficitChecks`), `stopHealthLogging`에서 리셋
테스트	`apps/web/lib/voice-agent/livekit-audio-chain-processor.test.ts`	정상→결손→결손→회복 4창 시나리오. ratio 값, WARN 1회, consecutive 2, discardReason 없음 고정

로그 읽는 법 (트리아지)

로그	레벨	의미
`Audio chain health` · `renderRatio ≥ 0.98`	info	정상. 0.998~1.000이 기대값
`Audio chain health` · `renderRatio < 0.98` 단발	info	백그라운드 복귀·시계 보정 등 단일 창 튐. WARN 없음
`Audio chain render deficit`	warn	결손 2회 연속(10초+). 단말 렌더 스레드가 블록을 버리는 중 → 지지직. 지속되는 동안 5초마다 반복
`Audio chain not rendering`	warn	currentTime 완전 정지(기존). 3회면 공유 ctx 폐기 대상

결손이 확인되면 LIVEKIT_PLAYOUT concealedRatio가 0에 가까운지 함께 본다. 0이면 네트워크 손실이 아니고, 지터버퍼가 커져도 결손의 부수 효과다(9/17: 30ms → 100~160ms).

리뷰 관전 포인트

구조

Date.now()는 단조 시계가 아니라 NTP 보정에 흔들릴 수 있다. performance.now()가 정석이지만, 단일 창 튐은 카운터가 리셋해 WARN을 만들지 않고 같은 파일의 다른 계측(startMonitoring)도 Date.now를 쓰므로 일관성을 택했다. 후속에서 바꿀 여지.

동작 확인

iOS WebKit에서 백그라운드 전환 뒤 복귀하면 setInterval이 늦게 돌아 첫 창의 wallDeltaMs가 수십 초가 될 수 있다. 그 사이 ctx가 suspended였다면 not rendering 분기로 빠지고, running이었다면 ratio가 1 근처로 나와야 한다. 실기기 로그로 첫 복귀 창이 오탐 WARN을 만들지 않는지 확인 필요(2회 연속 조건이 방어하지만 미검증).

로그량

결손이 12분 지속된 홍윤우 세션 기준 WARN 약 140줄. not rendering과 같은 정책이라 수용 가능하지만, 야간 트리아지 룰에서는 “WARN 존재”가 아니라 연속 구간 길이·최소 ratio로 판정해야 한다(야간 트리아지 원칙: 판정은 룰, “WARN이면 보고” 금지).

영향 범위

로깅 전용. markSharedContextUnhealthy·트랙·게인 어디에도 닿지 않아 revert만으로 원복된다. 임계값 0.98/2회는 사례 3건 기준이라 정상 세션에서 WARN이 보이면 임계값을 먼저 의심한다.

미해결

ratio는 “결손이 났다”까지만 말한다. 1차 원인(열/CPU 스로틀링, 저전력 모드, 활동 전환마다의 ctx 재구성)은 여전히 로그로 가를 수 없다. 홍윤우 문서가 제안한 outputLatency·활성 AudioContext 수·캔버스 fps 동시 기록은 이 PR 범위 밖.

검증

단위: pnpm exec tsx lib/voice-agent/livekit-audio-chain-processor.test.ts 전체 통과(기존 케이스 + 신규 1). test:livekit-vp 묶음의 나머지 7개 개별 통과. lesson-session.service.disconnect-race 실패는 develop에서도 동일한 사전 존재 실패.
타입: npx tsc --noEmit 에러 0.
실기기: 미검증. 저사양 iPhone(iOS 26, WKWebView)에서 지지직 구간에 Audio chain render deficit가 동반되는지, 정상 세션에서 WARN이 0인지 확인이 남아 있다.