Skip to content

Move log "Bot stopped" speaking from MediaSender to BaseOutputTransport - #5663

Open
NikolayShakin wants to merge 3 commits into
pipecat-ai:mainfrom
NikolayShakin:move_bot_stopped_speacking_logs
Open

Move log "Bot stopped" speaking from MediaSender to BaseOutputTransport#5663
NikolayShakin wants to merge 3 commits into
pipecat-ai:mainfrom
NikolayShakin:move_bot_stopped_speacking_logs

Conversation

@NikolayShakin

Copy link
Copy Markdown

a fix for #5662

@omChauhanDev

Copy link
Copy Markdown
Contributor

The placement makes sense: the log belongs where the frame is forwarded, not where TTS stops.

Two things the diff runs into, measured against 1f8a513dd.

The override drops the base class's default for direction. FrameProcessor.push_frame declares direction: FrameDirection = FrameDirection.DOWNSTREAM, and base_output.py calls it with one argument in four places, including the downstream BotStartedSpeakingFrame and BotStoppedSpeakingFrame pushes in MediaSender. With the diff applied, await transport.push_frame(BotStoppedSpeakingFrame()) raises TypeError: BaseOutputTransport.push_frame() missing 1 required positional argument: 'direction'; unpatched it succeeds. Driving a short TTS turn through process_frame(TTSStoppedFrame(...)), main logs the line once and the patched build zero times, the speaking events having stopped firing.

The suite stays green either way: _make_transport in tests/test_base_output_transport.py does transport.push_frame = AsyncMock(), so no test there calls the overridden method. 169 tests pass with the diff applied, across the eight modules mentioning BotStoppedSpeakingFrame.

Restoring the default is not the whole fix. _bot_stopped_speaking pushes a downstream frame and an upstream sibling, both BotStoppedSpeakingFrame, so the line then logs twice where main logs it once.

@NikolayShakin

Copy link
Copy Markdown
Author

Hi @omChauhanDev, thanks for the review. I added the default value for direction.

But I'm not sure how to properly fix this:

Restoring the default is not the whole fix. _bot_stopped_speaking pushes a downstream frame and an upstream sibling, both BotStoppedSpeakingFrame, so the line then logs twice where main logs it once.

Would it work if we only log on the downstream-ed(direction == FrameDirection.DOWNSTREAM) frames like this?

async def push_frame(self, frame: Frame, direction: FrameDirection = FrameDirection.DOWNSTREAM):
    """Push a frame to the next processor in the pipeline."""
    if isinstance(frame, BotStoppedSpeakingFrame) and direction == FrameDirection.DOWNSTREAM:
        destination = frame.transport_destination
        logger.debug(
            f"Bot{f' [{destination}]' if destination else ''} stopped speaking"
        )

    await super().push_frame(frame, direction)

@omChauhanDev

Copy link
Copy Markdown
Contributor

Yes, that filter is right. Measured on your e1aed0c85 with it applied: the line logs once for a TTS turn, matching unpatched main. Your current head without it logs twice, so the crash fix uncovered exactly that second case.

One difference from main it leaves. BotStoppedSpeakingFrame is a SystemFrame and BaseOutputTransport.process_frame forwards system frames straight to push_frame, so a BotStoppedSpeakingFrame this transport did not produce, passing through it downstream, is logged too: main logs zero for that, the filtered build logs one, tagged with whatever transport_destination the frame carried. I have not established that a real pipeline routes one that way, so it may be unreachable in practice.

The label is unchanged either way. _bot_stopped_speaking sets the downstream frame's transport_destination from the same self._destination the old log read.

@NikolayShakin

Copy link
Copy Markdown
Author

Thanks, @omChauhanDev, I added the direction check.
As for the BotStoppedSpeakingFrames that are not coming from the transport itself, I think it might acctually be useful to log the events in push_frame of the base transport, because these frames affect the logic, and it's better ot higlight the moment when the frame is pushed to the pipeline. It looks like in the current implementation, this kind of "external" BotStoppedSpeakingFrame will not produce any logs when pushed to the pipeline

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants