feat: split recording vs STT-processing time in turn logs

Log the captured speech-clip duration (녹음/음성) separately from the Whisper
transcription time (STT처리) so it's clear whether a slow turn is the
listening/recording or the transcription, per the user's request.
This commit is contained in:
javis-bot
2026-06-14 21:45:50 +09:00
parent 11a72cb296
commit 09afc21283

View File

@@ -459,14 +459,31 @@ def http_converse_stream():
# own Date.now() capture timestamps (same host, same clock). # own Date.now() capture timestamps (same host, same clock).
return int(time.time() * 1000) return int(time.time() * 1000)
# Length of the captured speech clip (16-bit mono PCM). This is the
# "음성 인식(녹음)" portion — how long the user actually spoke (+ the
# bot's trailing silence cutoff) — as opposed to "STT 처리", the Whisper
# transcription time below. Splitting them shows whether a slow turn is
# the listening/recording or the transcription.
try:
_frames, _sr = _read_wav_pcm(raw)
audio_sec = (len(_frames) / 2) / _sr if _sr else 0.0
except Exception:
audio_sec = 0.0
t0 = time.monotonic() t0 = time.monotonic()
stt = transcribe(raw) stt = transcribe(raw)
t_stt = time.monotonic() t_stt = time.monotonic()
transcript = stt.get("text", "") transcript = stt.get("text", "")
if not transcript: if not transcript:
print(
f"[bridge] ⏱️ turn 녹음(음성)={audio_sec:.1f}s STT처리(whisper)={t_stt - t0:.1f}s "
f"→ 인식 결과 없음 ({stt.get('note', '빈 결과')})",
flush=True,
)
yield json.dumps({"type": "meta", "transcript": "", "language": stt.get("language"), yield json.dumps({"type": "meta", "transcript": "", "language": stt.get("language"),
"reply": "", "error": stt.get("error"), "reply": "", "error": stt.get("error"),
"note": stt.get("note", "빈 결과"), "note": stt.get("note", "빈 결과"),
"audio_sec": round(audio_sec, 1),
"stt_sec": round(t_stt - t0, 1), "broadcast_action": None}) + "\n" "stt_sec": round(t_stt - t0, 1), "broadcast_action": None}) + "\n"
yield json.dumps({"type": "end"}) + "\n" yield json.dumps({"type": "end"}) + "\n"
return return
@@ -482,6 +499,7 @@ def http_converse_stream():
"reply": reply, "reply": reply,
"error": result.get("error"), "error": result.get("error"),
"note": "ok" if reply.strip() else "답변 없음", "note": "ok" if reply.strip() else "답변 없음",
"audio_sec": round(audio_sec, 1),
"stt_sec": round(t_stt - t0, 1), "stt_sec": round(t_stt - t0, 1),
"think_sec": round(t_think - t_stt, 1), "think_sec": round(t_think - t_stt, 1),
# Wall-clock LLM window (epoch ms) for the transcript-channel timing # Wall-clock LLM window (epoch ms) for the transcript-channel timing
@@ -516,8 +534,9 @@ def http_converse_stream():
"tts_end_ms": tts_end_ms, "tts_end_ms": tts_end_ms,
}) + "\n" }) + "\n"
print( print(
f"[bridge] ⏱️ turn stt={t_stt - t0:.1f}s think(LLM)={t_think - t_stt:.1f}s " f"[bridge] ⏱️ turn 녹음(음성)={audio_sec:.1f}s STT처리(whisper)={t_stt - t0:.1f}s "
f"tts={tts_total:.1f}s total={time.monotonic() - t0:.1f}s replylen={len(reply)} " f"think(LLM)={t_think - t_stt:.1f}s tts={tts_total:.1f}s "
f"total(STT~TTS)={time.monotonic() - t0:.1f}s replylen={len(reply)} "
f"transcript={transcript[:40]!r}", f"transcript={transcript[:40]!r}",
flush=True, flush=True,
) )