added logging for debugging

This commit is contained in:
Chad Bailey
2025-08-16 21:52:18 +00:00
parent c246b54d4d
commit 40605aef38
3 changed files with 35 additions and 2 deletions

View File

@@ -616,6 +616,9 @@ class ElevenLabsTTSService(AudioContextWordTTSService):
)
frame = TTSAudioRawFrame(audio, self.sample_rate, 1)
logger.debug(
f"[ELEVENLABS_AUDIO] Creating TTSAudioRawFrame with {len(audio)} bytes for context {received_ctx_id}"
)
await self.append_to_audio_context(received_ctx_id, frame)
if msg.get("alignment"):
@@ -1027,6 +1030,9 @@ class ElevenLabsHttpTTSService(WordTTSService):
if data and "audio_base64" in data:
await self.stop_ttfb_metrics()
audio = base64.b64decode(data["audio_base64"])
logger.debug(
f"[ELEVENLABS_AUDIO] Yielding TTSAudioRawFrame with {len(audio)} bytes"
)
yield TTSAudioRawFrame(audio, self.sample_rate, 1)
# Process alignment if present

View File

@@ -333,6 +333,9 @@ class TTSService(AIService):
elif isinstance(frame, TTSUpdateSettingsFrame):
await self._update_settings(frame.settings)
elif isinstance(frame, BotStoppedSpeakingFrame):
logger.warning(
f"[TTS_RESUME] {self.__class__.__name__} received BotStoppedSpeakingFrame"
)
await self._maybe_resume_frame_processing()
await self.push_frame(frame, direction)
else:
@@ -376,11 +379,15 @@ class TTSService(AIService):
async def _maybe_pause_frame_processing(self):
if self._processing_text and self._pause_frame_processing:
logger.warning(f"[TTS_PAUSE] {self.__class__.__name__} pausing frame processing")
await self.pause_processing_frames()
async def _maybe_resume_frame_processing(self):
if self._pause_frame_processing:
logger.warning(f"[TTS_RESUME] {self.__class__.__name__} resuming frame processing")
await self.resume_processing_frames()
else:
logger.debug(f"[TTS_RESUME] {self.__class__.__name__} resume called but not paused")
async def _process_text_frame(self, frame: TextFrame):
text: Optional[str] = None

View File

@@ -503,6 +503,9 @@ class BaseOutputTransport(FrameProcessor):
num_channels=frame.num_channels,
)
chunk.transport_destination = self._destination
logger.debug(
f"[AUDIO_QUEUE] Putting {chunk.__class__.__name__} with {len(chunk.audio)} bytes into audio queue"
)
await self._audio_queue.put(chunk)
self._audio_buffer = self._audio_buffer[self._audio_chunk_size :]
@@ -582,15 +585,18 @@ class BaseOutputTransport(FrameProcessor):
async def _bot_stopped_speaking(self):
"""Handle bot stopped speaking event."""
if self._bot_speaking:
logger.debug(
f"Bot{f' [{self._destination}]' if self._destination else ''} stopped speaking"
logger.warning(
f"[BOT_STOPPED] Bot stopped speaking - sending BotStoppedSpeakingFrame upstream"
)
downstream_frame = BotStoppedSpeakingFrame()
downstream_frame.transport_destination = self._destination
upstream_frame = BotStoppedSpeakingFrame()
upstream_frame.transport_destination = self._destination
logger.debug(f"[BOT_STOPPED] Pushing downstream BotStoppedSpeakingFrame")
await self._transport.push_frame(downstream_frame)
logger.debug(f"[BOT_STOPPED] Pushing upstream BotStoppedSpeakingFrame")
await self._transport.push_frame(upstream_frame, FrameDirection.UPSTREAM)
self._bot_speaking = False
@@ -598,6 +604,8 @@ class BaseOutputTransport(FrameProcessor):
# Clean audio buffer (there could be tiny left overs if not multiple
# to our output chunk size).
self._audio_buffer = bytearray()
else:
logger.debug(f"[BOT_STOPPED] _bot_stopped_speaking called but bot was not speaking")
async def _handle_frame(self, frame: Frame):
"""Handle various frame types with appropriate processing.
@@ -624,12 +632,24 @@ class BaseOutputTransport(FrameProcessor):
async def without_mixer(vad_stop_secs: float) -> AsyncGenerator[Frame, None]:
while True:
try:
logger.debug(
f"[AUDIO_QUEUE] Waiting for audio frame (timeout={vad_stop_secs}s)"
)
start_time = time.time()
frame = await asyncio.wait_for(
self._audio_queue.get(), timeout=vad_stop_secs
)
wait_time = time.time() - start_time
logger.debug(
f"[AUDIO_QUEUE] Got frame {frame.__class__.__name__} after {wait_time:.3f}s"
)
self._transport.reset_watchdog()
yield frame
except asyncio.TimeoutError:
wait_time = time.time() - start_time
logger.warning(
f"[AUDIO_QUEUE] TIMEOUT after {wait_time:.3f}s - triggering bot_stopped_speaking"
)
self._transport.reset_watchdog()
# Notify the bot stopped speaking upstream if necessary.
await self._bot_stopped_speaking()