음성 대화 앱 세 개의 세션 기록을 훑다가 눈에 걸린 숫자가 있었습니다. 전체 271건 중 51건, 그러니까 19%가 양방향 오디오 토큰이 0이었습니다. 연결은 됐는데 아무 소리도 오가지 않은 세션입니다.
토큰 발급 횟수는 평균 1.0으로 정상이었습니다. 소켓은 열렸다는 뜻입니다. 그렇다면 마이크가 안 잡혔거나, 오디오 스트림이 서버까지 못 갔거나, 둘 중 하나입니다. 저는 오디오 경로를 파기 시작했습니다.
당신의 대시보드에 있는 0은, 정말 "일어나지 않았다"는 뜻입니까?
세 시간쯤 파고 나서
에코 게이트를 읽었습니다. 재생 중에만 작동하고 아니면 투명하게 통과시킵니다. 마이크 권한 경로를 읽었습니다. 거부되면 예외를 던지고 그 예외는 화면까지 올라갑니다. 캡처 버퍼 워치독도 있었습니다. 3초 뒤에 버퍼가 0이면 오디오를 한 번 재시작합니다.
전부 정상이었습니다. 그래서 더 깊이 갔습니다. 서버가 토큰을 어디서 기록하는지 보러 갔습니다.
session-end: audio_in_tokens: Number(tok.audio_in ?? 0)
heartbeat: (토큰을 받는 코드가 없음)여기서 멈췄습니다.
그 51건은 어떤 세션이었나
abandoned 상태였습니다. 그리고 abandoned가 무엇인지 코드에서 확인해 보니, 클라이언트가 세션 종료를 호출하지 않아서 다음 세션을 시작할 때 뒤늦게 정리된 세션이었습니다.
토큰은 그 종료 호출에서만 기록됩니다.
즉 abandoned 세션은 정의상 토큰이 0입니다. 오디오가 오갔든 아니든 상관없습니다. 제가 "19%가 무음"이라고 읽은 것은 관찰이 아니라 동어반복이었습니다. "종료를 호출하지 않은 세션은 종료 시점에 기록되는 값이 비어 있다" — 여기에는 아무 정보가 없습니다.
여기서 선택이 갈립니다
이 지점에서 두 갈래가 있습니다. 하나는 "그럼 그 51건은 버리고 나머지로 다시 세자"이고, 다른 하나는 "일단 계측을 추가해서 2주 뒤에 다시 보자"입니다.
당신이라면 어느 쪽을 고르겠습니까?
저는 전자를 골랐습니다. 종료가 정상적으로 호출된 218건만 남기고 다시 셌습니다. 무음 비율은 66%였습니다 — 19%가 아니라. 숫자가 오히려 커졌고, 그제야 진짜 질문을 할 수 있었습니다.
곁가지에서 결함이 하나 나왔습니다
이 구조에는 실제 문제가 있었습니다. 종료를 호출하지 않은 세션의 사용량이 영영 기록되지 않습니다. 분은 서버가 별도로 정산하지만 토큰은 0으로 남습니다. 그만큼 원가가 과소 집계되고 있었습니다.
고친 방향은 단순합니다. 15초마다 오는 하트비트에 누적 사용량을 함께 싣고, 서버가 필드별로 큰 값을 취합니다.
mergeTokenUsage(current, incoming) -> 필드별 maxmax인 이유는 앱이 재연결하면 누적을 0부터 다시 세기 때문입니다. 들어온 값을 그대로 쓰면 이미 기록된 사용량이 사라집니다. 같은 이유로 소비 시간도 단조 증가로 막고 있었는데, 토큰만 그 보호 밖에 있었습니다.
토큰을 안 보내는 구버전 앱과도 함께 돌아야 해서 값이 없으면 기존 값을 그대로 둡니다. 서버를 앱보다 먼저 배포하기 때문입니다.
자가진단
- 당신의 지표 중 특정 코드 경로에서만 기록되는 값이 있습니까? 그 경로를 타지 않은 표본에서 그 값은 무엇으로 읽힙니까?
- "0"과 "측정되지 않음"이 같은 칸에 들어가 있지는 않습니까?
- 상태 라벨(
abandoned,failed,timeout)이 누가 언제 붙이는지 코드로 확인해 본 적이 있습니까?
솔직한 부분
저는 이 함정을 몰라서 밟은 게 아닙니다. 같은 프로젝트에서 이미 "판정 전에 그 지표가 무엇을 못 보는지부터 확인하라"고 적어둔 적이 있습니다. 그러고도 며칠 뒤에 같은 종류의 숫자를 액면가로 읽었습니다.
테스트가 한 건도 실행되지 않았는데 초록불이었던 일이나 빈 키가 모든 게이트를 통과한 일과 같은 계열입니다. 숫자가 거짓말을 하는 게 아니라, 제가 그 숫자에게 대답할 수 없는 질문을 던진 겁니다.
지금 당신의 대시보드에서 0이 가장 많은 열을 하나 골라, 그 값이 어느 함수에서 쓰이는지 딱 한 번만 grep 해보세요. 저는 그 한 번을 세 시간 늦게 했습니다.