OTel span으로 추적하는 4계층 음성 에이전트 지연 시간 스택

**

내가 ASR, LLM, TTS, 그리고 클라이언트를 OpenTelemetry로 계측하는 방법과 각 계층에서 실제로 확인하는 수치

**

요약 (TL;DR). 음성 에이전트는 네 가지 움직이는 부품이 결합된 형태입니다: 음성을 텍스트로 변환하는 음성 인식 (ASR), 답변을 작성하는 모델 (LLM), 텍스트를 음성으로 변환하는 음성 합성 (TTS), 그리고 오디오를 다시 재생하는 클라이언트입니다. 엔드 투 엔드 (End-to-end) 지연 시간은 특정 턴에서 이 네 가지 중 무엇이 느린지를 숨겨버립니다. 그래서 저는 이를 하나의 숫자로 추적하는 것을 중단하고, 공유된 세션 ID (session id)를 가진 각각의 단계를 개별적인 OTel span으로 추적하기 시작했습니다. 제가 가장 주의 깊게 보는 수치는 '바지인 (barge-in)'입니다. 즉, 사용자가 에이전트의 말을 끊고 말을 시작했을 때, 에이전트가 실제로 오디오 전송을 중단할 때까지 몇 밀리초 (ms)가 걸리는지를 봅니다. 저희 설정에서는 이 수치를 200ms 미만으로 유지하고자 하며, p95 바지인 수치가 이를 넘어서기 시작하면 에이전트가 사용자와 대화하는 것이 아니라 사용자에게 일방적으로 말을 거는 것처럼 느껴집니다. 아래 내용은 제가 span을 연결하는 방식, 각 span에 들어가는 속성 (attributes), 그리고 계층별로 제가 알람을 설정하는 p95 수치에 대한 것입니다.

제가 계속해서 말하고 있고, 계속해서 사실로 드러나는 점은 이것입니다: 음성 에이전트가 프로덕션 환경에서 실패하는 이유는 단순한 지연 시간 때문이 아니라, 아무도 오디오와 LLM 파이프라인을 함께 시뮬레이션하지 않았기 때문입니다. 빠른 ASR, 빠른 모델, 빠른 TTS를 갖추고 있더라도 여전히 망가진 것처럼 느껴지는 음성 에이전트가 있을 수 있습니다. 왜냐하면 실패는 그들 사이의 이음새 (seams)와, 단일 단계 벤치마크로는 건드릴 수 없는 부분들 (바지인, 지터 (jitter))에 존재하기 때문입니다. 추적 (Tracing)은 제가 이 이음새들을 드러나게 만드는 방법입니다.

계층을 설명하기 전에 참고할 점이 있습니다. 이것은 단지 저희가 실행하는 설정, 저희가 방출하는 span, 그리고 각 속성을 추가하게 만든 실수들에 대한 기록입니다. 이 중 일부는 아마 저희 스택에 특화된 것이라 다른 곳에는 적용되지 않을 수 있습니다. 가능한 경우 그 부분을 표시하겠습니다.

하나의 턴의 형태, 그리고 왜 하나의 span만으로는 부족한가

하나의 턴(One turn)은 다음과 같습니다: 사용자가 무언가를 말하면, 에이전트가 다시 무언가를 말합니다. 그 이면에서는 대략 다음과 같은 일이 일어납니다: 오디오 프레임(audio frames)이 들어오고, ASR(Automatic Speech Recognition)이 이를 텍스트로 변환합니다(진행 과정에서 스트리밍 방식의 부분 결과물(streaming partials)을 생성함). 이 텍스트와 히스토리(history)가 LLM(Large Language Model)으로 전달되면, LLM은 토큰(tokens)을 다시 스트리밍합니다. 텍스트가 출력됨에 따라 TTS(Text-to-Speech)가 이를 오디오로 변환하며, 이 또한 스트리밍 방식으로 이루어집니다. 클라이언트는 오디오 프레임을 수신하여 재생하며, 지터(jitter)를 완화하기 위해 약간의 버퍼링(buffering)을 수행합니다.

만약 전체 턴을 하나의 span으로 감싸고 이를 voice.turn이라고 부른다면, 전체 지속 시간(duration)은 알 수 있지만 이를 바탕으로 조치를 취할 수 있는 능력은 거의 없습니다. 1,400ms의 턴은 첫 번째 토큰(first token)이 느리게 생성된 것일 수도 있고, TTS가 시작하기 전에 전체 문장이 완성되기를 기다린 것일 수도 있으며, 혹은 클라이언트가 너무 공격적으로 버퍼링을 수행한 것일 수도 있습니다. 총 시간은 같지만, 해결 방법은 세 가지로 다릅니다.

따라서 부모 span은 voice.turn이 되고, 각 단계는 자식 span(child span)이 됩니다. 모든 span은 동일한 audio.session_id와 audio.turn_id를 포함하므로, Tempo에서 하나의 턴을 추출하여 시간 순서대로 나열된 네 가지 단계를 모두 확인할 수 있습니다. 스트리밍 단계에서 제가 가장 중요하게 생각하는 속성(attribute)은 전체 지속 시간이 아닙니다. 바로 첫 번째 바이트(first byte), 즉 해당 단계가 첫 번째 유용한 출력을 생성할 때까지 걸린 시간입니다. 사용자가 느끼는 것은 바로 이 첫 번째 바이트입니다. 세 단계 모두 스트리밍 방식이므로, 사용자는 마지막 바이트가 아닌 첫 번째 바이트가 나올 때부터 진행 상황을 인지하기 시작하기 때문입니다.

import time
from contextlib import contextmanager
from opentelemetry import trace
...

LLM 단계를 중심으로 호출하기: 스트리밍 루프 내에서 토큰이 처음 나타나는 시점에 first_byte()를 호출하면, 래퍼(wrapper)가 타이밍 계산을 수행합니다.

async def run_llm_stage(session_id, turn_id, messages, llm_client):
    chunks = []
    with stage_span("llm", session_id, turn_id) as first_byte:
...

저는 의도적으로 time.time() 대신 time.monotonic()을 사용합니다. 벽시계 시간(Wall clock)은 (NTP 보정 등으로 인해) 점프할 수 있으며, 1초 미만의 예산(budget)을 다룰 때 시계가 뒤로 가면 백분위수(percentiles)를 오염시키는 음수 지연 시간이 발생하기 때문입니다. 한 가지 더 골치 아프게 배운 점은, audio.session_id는 카디널리티(cardinality)가 높다는 것입니다. 그래서 트레이스(trace) 조회를 위해 스팬 속성(span attribute)으로는 유지하지만, 메트릭 레이블(metric label)로 만들지는 않습니다. 스테이지(Stage)는 메트릭 레이블로 가고, 세션 ID는 트레이스에 남겨둡니다.

ASR: 최종 전사(final transcript)가 아닌 첫 번째 부분 전사(first partial)를 측정하라

제가 처음에 했던 실수는 ASR을 오디오 입력부터 최종 전사 출력까지의 시간으로 측정하는 것이었습니다. 그 수치는 실제 값이긴 하지만 사용자가 느끼는 체감과는 일치하지 않습니다. 스트리밍 ASR은 부분 전사(partial transcript)를 빠르게 제공한 뒤 이를 정제하기 때문입니다. 그래서 스팬에는 두 가지 숫자가 들어갑니다. audio.first_byte_ms는 첫 번째 부분 전사까지의 시간이며, 최종 전사까지의 시간은 별도로 저장합니다.

ASR의 또 다른 속성으로 자리를 잡은 것은 최종 전사가 마지막 부분 전사와 심하게 불일치했는지 여부입니다. 고객이 주문을 확인하고 싶다고 말한 것을 ASR이 '취소(cancel)'라는 단어로 잘못 변환하여 에이전트가 그대로 실행해 버린 사고가 있었습니다. 그 이후로 저는 최종 결과물이 부분 전사를 얼마나 수정했는지에 대한 대략적인 측정치를 기록하기 시작했습니다. 덕분에 큰 폭의 후기 수정 사항이 화가 난 고객의 지원 티켓으로 나타나기 전에 트레이스에서 먼저 나타나게 되었습니다. 제가 ASR에서 확인하는 지표는 '첫 번째 부분 전사까지의 시간(time to first partial)'의 p95입니다. 저희 설정에서는 대부분 150ms 미만이며, 이 수치가 올라갈 때는 ASR 모델의 문제라기보다 클라이언트로부터 오디오 프레임이 제때 도착하지 않는 경우가 거의 대부분입니다. 전체 과정을 트레이싱해야 하는 아주 좋은 예시입니다.

LLM: 첫 번째 토큰이 승부처이며, 끼어들기(barge-in)도 여기서 발생한다

모델 단계에서는 전체 생성 시간(total generation time)이 체감 경험에 거의 영향을 미치지 않는데, 이는 TTS가 토큰이 도착하는 대로 소비하기 때문입니다. 중요한 것은 첫 번째 토큰까지의 시간(time to first token)입니다. 만약 모델이 첫 번째 토큰을 내놓기까지 600ms가 걸린다면, 사용자는 말을 마친 후 600ms 동안 침묵을 듣게 되며, 이는 에이전트가 멈춘 것처럼 느껴집니다. 따라서 LLM 스팬의 핵심 속성은 첫 번째 토큰까지의 시간입니다.

Barge-in(끼어들기)은 사람들이 계측(instrument)하는 것을 잊어버리는 부분이며, 만약 제가 처음부터 다시 시작한다면 가장 먼저 계측할 부분입니다. 이는 에이전트가 여전히 말하고 있는 동안 사용자가 말을 시작할 때 발생하는 현상입니다. 측정 지표는 다음과 같습니다: 음성 활동 감지(Voice-Activity Detection, VAD)가 작동한 순간부터 에이전트의 출력 오디오가 실제로 조용해지는 순간까지의 시간입니다. 우리가 처음 이를 측정했을 때 약 500ms 정도였으며 매우 나쁜 경험으로 느껴졌는데, 세부 분석 결과 대부분의 시간은 감지(detection) 과정에서 발생하는 것이 아니었습니다. 그것은 이미 클라이언트로 전송되어 취소할 수 없는 버퍼링된 TTS 오디오 때문이었습니다. 우리는 지터(jitter)에 대응하기 위해 공격적으로 버퍼를 쌓았고, 바로 그 버퍼가 Barge-in을 느리게 만들었습니다. 트레이싱(Tracing)을 통해 두 목표가 서로 충돌하고 있음을 확인할 수 있었습니다. 현재 우리는 대략 180ms p95 수준에 도달해 있습니다.

def run_barge_in(session_id, turn_id, vad, agent_audio):
    with stage_span("barge_in", session_id, turn_id) as first_byte:
        span = trace.get_current_span()
...

솔직히 모델 계층을 위해 제가 벽에 붙여두는 숫자는 두 가지입니다. 바로 p95 첫 번째 토큰(first token)과 p95 Barge-in 침묵(barge-in silence) 시간입니다. 두 숫자 모두 좋아야 합니다.

TTS: 첫 번째 오디오 청크, 그리고 문장 사이의 간격

TTS 역시 스트리밍 방식이므로, 중요한 속성은 재생 가능한 첫 번째 오디오 청크인 첫 번째 바이트(first byte)입니다. TTS의 p95 첫 번째 바이트가 350ms를 넘어가면 우리는 페이지 호출(page)을 하는데, 그 시간을 넘어서면 사용자가 말을 마친 후 에이전트가 시작할 때까지의 일시 정지가 너무 길어져서 테스터들이 에이전트가 너무 깊게 생각하는 것 같다고 묘사하기 때문입니다. 단일한 첫 번째 바이트 수치만으로는 놓칠 수 있는 두 번째 TTS 요소가 있습니다: 오디오가 흐르기 시작한 후 청크(chunk) 사이의 간격입니다. 만약 TTS가 문장 중간에 멈추면 사용자는 끊김 현상을 듣게 되지만, 평균 지연 시간(average latency)은 정상처럼 보일 수 있습니다. 그래서 저는 TTS 스팬(span)에 가장 큰 청크 간 간격(inter-chunk gap)을 기록합니다.

저는 ASR, 모델, 그리고 TTS가 각각 물리적으로는 약간씩 다른 의미의 "첫 번째 바이트"를 의미함에도 불구하고, 의도적으로 모두 동일한 audio.first_byte_ms 속성 이름을 사용하게 합니다. 이름이 같으면 단 한 번의 쿼리로 세 단계 모두에서 첫 번째 바이트를 가져와 한 화면에서 비교할 수 있기 때문입니다.

클라이언트: 지터(jitter)는 숫자이며, 서버에서는 이를 볼 수 없습니다

위의 모든 내용은 서버 측(server side)에 해당합니다. 클라이언트는 제어할 수 없는 네트워크를 통해 오디오를 수신하고 이를 재생합니다. 여기서 적은 바로 지터(jitter), 즉 프레임이 불규칙하게 도착하는 현상입니다. 서버 측에서는 모든 것이 정상적으로 보일 수 있지만, 사용자는 끊기는 오디오를 듣게 될 수 있습니다. 따라서 클라이언트는 턴(turn)마다 자체적인 스팬(span)을 생성하며, 이때 측정한 지터(jitter) 값과 설정된 버퍼 깊이(buffer depth)를 동일한 audio.session_id와 함께 동일한 컬렉터(collector)로 전송합니다. 이제 통화 품질이 불량한 경우, 세 개의 서버 스팬 바로 옆에 지터(jitter) 수치가 표시됩니다. 솔직한 주의 사항을 말씀드리자면, 클라이언트의 시계는 서버와 동기화되어 있지 않으므로 클라이언트의 타임스탬프(timestamp)는 대략적인 값으로 취급해야 합니다. 저는 클라이언트 스팬이 보고하는 지터(jitter) 및 버퍼(buffer) 값 자체는 신뢰하지만, 클라이언트의 시계를 밀리초(ms) 단위로 서버와 일치시키는 용도로는 신뢰하지 않습니다.

이것은 제가 저장해 둔 TraceQL입니다. 단계별로 그룹화된 첫 번째 바이트 지연 시간(first-byte latency)의 p95 값을 추출합니다.

{ span.audio.stage != "" && span.audio.first_byte_ms >= 0 }
  | select(span.audio.stage, span.audio.first_byte_ms)
  | quantile_over_time(span.audio.first_byte_ms, 0.95) by (span.audio.stage)

>= 0 필터가 있는 이유는 아무것도 생성하지 않은 단계는 first_byte_ms = -1이 되며, 이러한 값들이 백분위수(percentile)를 오염시키는 것을 원치 않기 때문입니다. 집계 데이터에서 단일 불량 통화로 넘어가려면 세션으로 필터링합니다: { span.audio.session_id = "sess_8f21c0" }. 이렇게 하면 해당 세션의 모든 스팬이 시간 순서대로 나타나며, 이것이 바로 제가 모든 스팬에 session_id를 넣은 유일한 이유입니다. 백분위수에 대해 한 말씀 드리자면, 이는 대응 방식 자체를 바꾸기 때문입니다. p50 첫 번째 토큰(first token) 지연 시간은 280ms일 수 있고 괜찮아 보일 수 있지만, p99는 1,900ms일 수 있습니다. 음성 통화에서 이 p99는 2초간의 침묵을 경험하고 아마도 허공에 대고 "여보세요? 거기 계세요?"라고 말했을 실제 사람을 의미합니다. 평균값(averages)은 대부분 무시합니다.

제가 여전히 고민 중인 부분

통화가 이미 진행 중이기 전까지는 사용자의 네트워크를 볼 수 없는데, 클라이언트 재생 버퍼 (client playout buffer)를 어떻게 설정해야 할까요? 기침 소리나 "음-흠" 같은 소리, 혹은 사용자의 강아지 소리에 VAD (Voice Activity Detection)가 작동할 때, 끼어들기 (barge-in) 모델이 과연 적절한 모델일까요? 그리고 이 모든 것 아래에 깔린 근본적인 질문은 이것입니다. 이제 모든 계층을 추적 (trace)할 수 있게 되었지만, 결국 사람이 직접 들어보는 방식이 아니라면 "이 통화는 자연스러웠다"라고 말할 수 있는 수치를 여전히 얻지 못하고 있습니다. 추적 (tracing)은 시간이 어디로 흘러갔는지는 알려주지만, 대화가 좋았는지까지는 알려주지 않습니다.

만약 여러분이 음성 에이전트 (voice agent)에 계측 (instrumenting)을 수행하고 있고, 이번 주에 단 하나의 스팬 (span)만 추가할 시간이 있다면, 끼어들기 (barge-in)를 추가하십시오. 그것은 아무도 측정하지 않지만, 사용자가 가장 빠르게 체감하는 요소입니다.