diff --git a/.changeset/late-playback-started-dropped-turns.md b/.changeset/late-playback-started-dropped-turns.md new file mode 100644 index 000000000..b588d191a --- /dev/null +++ b/.changeset/late-playback-started-dropped-turns.md @@ -0,0 +1,9 @@ +--- +'@livekit/agents': patch +--- + +fix(voice): stop dropping agent turns whose playback starts after audio forwarding completes (#1909, #1960; port of livekit/agents#5039). + +`forwardAudio` used to reject `firstFrameFut` (and detach its `PLAYBACK_STARTED` listener) in its `finally` block whenever no frame had played by the time forwarding finished. Two real scenarios hit this window: a speech paused in the thinking state by a brief user sound, whose buffered first frame only plays after the false interruption clears (#1909), and DataStream avatar outputs with `waitPlaybackStart: true`, which deliver `lk.playback_started` ~1s after frames were captured (#1960). In both cases the late playback-started event found nothing listening, the reply was classified "skipped", and the turn was silently removed from the chat context while the agent never entered the `speaking` state. + +The `PLAYBACK_STARTED` listener now lives in `performAudioForwarding` so it outlives the forwarding task, and `forwardAudio` no longer settles the future; the reply tasks (including the `say()` path) settle it once the playout window ends, which also detaches the listener. A reported non-zero playback position on interruption is additionally honored as evidence of partial playback — but only when the segment actually captured a frame into the output (tracked via the output's segment count, which is also what makes the reported position fresh rather than stale) — covering avatars whose playback-started RPC races the interruption itself. diff --git a/agents/src/voice/agent_activity.ts b/agents/src/voice/agent_activity.ts index 656646681..0217c2589 100644 --- a/agents/src/voice/agent_activity.ts +++ b/agents/src/voice/agent_activity.ts @@ -2493,6 +2493,7 @@ export class AgentActivity implements RecognitionHooks { } }; + let audioOut: _AudioOut | null = null; if (!audioOutput) { if (textOut) { textOut.firstTextFut.await @@ -2500,7 +2501,6 @@ export class AgentActivity implements RecognitionHooks { .catch(() => this.logger.debug('firstTextFut cancelled before first frame')); } } else { - let audioOut: _AudioOut | null = null; if (!audio) { // generate audio using TTS const [ttsTask, ttsGenData] = performTTSInference( @@ -2541,53 +2541,73 @@ export class AgentActivity implements RecognitionHooks { .catch(() => this.logger.debug('firstFrameFut cancelled before first frame')); } - await speechHandle.waitIfNotInterrupted(tasks.map((task) => task.result)); - - if (audioOutput) { - await speechHandle.waitIfNotInterrupted([audioOutput.waitForPlayout()]); - } + try { + await speechHandle.waitIfNotInterrupted(tasks.map((task) => task.result)); - if (speechHandle.interrupted) { - replyAbortController.abort(); - await cancelAndWait(tasks, AgentActivity.REPLY_TASK_CANCEL_TIMEOUT); if (audioOutput) { - audioOutput.clearBuffer(); - await audioOutput.waitForPlayout(); + await speechHandle.waitIfNotInterrupted([audioOutput.waitForPlayout()]); } - } - if (addToChatCtx) { - const replyStoppedSpeakingAt = Date.now(); - const replyAssistantMetrics: MetricsReport = {}; - if (replyTtsGenData?.ttfb !== undefined) { - replyAssistantMetrics.ttsNodeTtfb = replyTtsGenData.ttfb; + if (speechHandle.interrupted) { + replyAbortController.abort(); + await cancelAndWait(tasks, AgentActivity.REPLY_TASK_CANCEL_TIMEOUT); + if (audioOutput) { + audioOutput.clearBuffer(); + await audioOutput.waitForPlayout(); + } } - if (replyStartedSpeakingAt !== undefined) { - replyAssistantMetrics.startedSpeakingAt = replyStartedSpeakingAt / 1000; // ms -> seconds - replyAssistantMetrics.stoppedSpeakingAt = replyStoppedSpeakingAt / 1000; // ms -> seconds - if (replyStartedForwardingAt !== undefined) { - replyAssistantMetrics.playbackLatency = - (replyStartedSpeakingAt - replyStartedForwardingAt) / 1000; // ms -> seconds + if (addToChatCtx) { + const replyStoppedSpeakingAt = Date.now(); + const replyAssistantMetrics: MetricsReport = {}; + if (replyTtsGenData?.ttfb !== undefined) { + replyAssistantMetrics.ttsNodeTtfb = replyTtsGenData.ttfb; } + if (replyStartedSpeakingAt !== undefined) { + replyAssistantMetrics.startedSpeakingAt = replyStartedSpeakingAt / 1000; // ms -> seconds + replyAssistantMetrics.stoppedSpeakingAt = replyStoppedSpeakingAt / 1000; // ms -> seconds + + if (replyStartedForwardingAt !== undefined) { + replyAssistantMetrics.playbackLatency = + (replyStartedSpeakingAt - replyStartedForwardingAt) / 1000; // ms -> seconds + } + } + + const message = ChatMessage.create({ + role: 'assistant', + content: textOut?.text || '', + interrupted: speechHandle.interrupted, + metrics: replyAssistantMetrics, + }); + this.agent._chatCtx.insert(message); + this.agentSession._conversationItemAdded(message); } - const message = ChatMessage.create({ - role: 'assistant', - content: textOut?.text || '', - interrupted: speechHandle.interrupted, - metrics: replyAssistantMetrics, - }); - this.agent._chatCtx.insert(message); - this.agentSession._conversationItemAdded(message); + if (this.agentSession.agentState === 'speaking') { + this.agentSession._updateAgentState('listening'); + if (this.audioRecognition) { + this.audioRecognition.onEndOfAgentSpeech(Date.now()); + } + this.restoreInterruptionByAudioActivity(); + } + } finally { + // In a finally so the listener is dropped even if an await above throws — + // otherwise it would leak on the shared audioOutput. + this.settleFirstFrameFut(audioOut); } + } - if (this.agentSession.agentState === 'speaking') { - this.agentSession._updateAgentState('listening'); - if (this.audioRecognition) { - this.audioRecognition.onEndOfAgentSpeech(Date.now()); - } - this.restoreInterruptionByAudioActivity(); + /** + * Reject `firstFrameFut` if it is still pending, dropping the PLAYBACK_STARTED + * listener registered in `performAudioForwarding`. Called by the reply tasks once + * the playout window has ended (finished or interrupted). `forwardAudio` no longer + * settles the future itself so that a frame which plays late — after a + * false-interruption resume (#1909) or a remote avatar's deferred + * `lk.playback_started` notification (#1960) — can still resolve it. + */ + private settleFirstFrameFut(audioOut: _AudioOut | null | undefined): void { + if (audioOut && !audioOut.firstFrameFut.done) { + audioOut.firstFrameFut.reject(new Error('playout finished before playback started')); } } @@ -2895,7 +2915,20 @@ export class AgentActivity implements RecognitionHooks { if (audioOutput) { audioOutput.clearBuffer(); const interruptedPlaybackEv = await audioOutput.waitForPlayout(); - if (output.audioOut?.firstFrameFut.done && !output.audioOut.firstFrameFut.rejected) { + // A reported playback position is proof of partial playback even when + // the playback-started notification hasn't arrived yet (remote avatar + // outputs deliver it via RPC, which can race with the interruption). + // It only counts as evidence when THIS segment bumped the output's + // segment count — the same condition under which waitForPlayout waits + // for this segment's playback event instead of returning a stale one + // from a previous segment (see _AudioOut.capturedSegmentsBefore). + const playedOwnFrame = + output.audioOut != null && + audioOutput.capturedPlayoutSegments > output.audioOut.capturedSegmentsBefore; + if ( + (output.audioOut?.firstFrameFut.done && !output.audioOut.firstFrameFut.rejected) || + (playedOwnFrame && interruptedPlaybackEv.playbackPosition > 0) + ) { output.played = 'partial'; output.playbackPositionInS = interruptedPlaybackEv.playbackPosition; output.synchronizedTranscript = interruptedPlaybackEv.synchronizedTranscript; @@ -2917,6 +2950,9 @@ export class AgentActivity implements RecognitionHooks { } finally { replyAbortController.signal.removeEventListener('abort', abortSegment); await cancelAndWait(forwardTasks, AgentActivity.REPLY_TASK_CANCEL_TIMEOUT); + // The segment's playout window is over; settle a still-pending + // firstFrameFut so the playback-started listener is detached. + this.settleFirstFrameFut(output.audioOut); } }; @@ -3449,7 +3485,20 @@ export class AgentActivity implements RecognitionHooks { if (audioOutput) { audioOutput.clearBuffer(); const playbackEv = await audioOutput.waitForPlayout(); - if (output.audioOut?.firstFrameFut.done && !output.audioOut.firstFrameFut.rejected) { + // A reported playback position is proof of partial playback even when + // the playback-started notification hasn't arrived yet (remote avatar + // outputs deliver it via RPC, which can race with the interruption). + // It only counts as evidence when THIS message bumped the output's + // segment count — the same condition under which waitForPlayout waits + // for this message's playback event instead of returning a stale one + // from a previous message (see _AudioOut.capturedSegmentsBefore). + const playedOwnFrame = + output.audioOut != null && + audioOutput.capturedPlayoutSegments > output.audioOut.capturedSegmentsBefore; + if ( + (output.audioOut?.firstFrameFut.done && !output.audioOut.firstFrameFut.rejected) || + (playedOwnFrame && playbackEv.playbackPosition > 0) + ) { output.played = 'partial'; output.playbackPositionInS = playbackEv.playbackPosition; output.synchronizedTranscript = playbackEv.synchronizedTranscript; @@ -3471,6 +3520,9 @@ export class AgentActivity implements RecognitionHooks { } finally { abortController.signal.removeEventListener('abort', abortMessage); await cancelAndWait(forwardTasks, AgentActivity.REPLY_TASK_CANCEL_TIMEOUT); + // The message's playout window is over; settle a still-pending + // firstFrameFut so the playback-started listener is detached. + this.settleFirstFrameFut(output.audioOut); } }; diff --git a/agents/src/voice/agent_activity_interrupted_commit.test.ts b/agents/src/voice/agent_activity_interrupted_commit.test.ts index 3eeb53e92..f6390df18 100644 --- a/agents/src/voice/agent_activity_interrupted_commit.test.ts +++ b/agents/src/voice/agent_activity_interrupted_commit.test.ts @@ -5,6 +5,7 @@ import { AudioFrame } from '@livekit/rtc-node'; import { ReadableStream } from 'node:stream/web'; import { describe, expect, it, vi } from 'vitest'; import { initializeLogger } from '../log.js'; +import { Future } from '../utils.js'; import { Agent } from './agent.js'; import { AgentSession } from './agent_session.js'; import { AgentSessionEventTypes, type ConversationItemAddedEvent } from './events.js'; @@ -42,6 +43,74 @@ class InterruptibleOutput extends AudioOutput { } } +// Audio sink that mimics a DataStream avatar output (waitPlaybackStart: true): +// frames are accepted faster than real time and playback-started is only +// reported LATER, via an out-of-band notification (the `lk.playback_started` +// RPC from the remote avatar worker) — typically after forwarding has already +// completed. `notifyPlaybackStarted` simulates that RPC arriving. +class DeferredStartOutput extends AudioOutput { + onFirstFrameCaptured?: () => void; + playbackPosition = 0; + private captured = false; + constructor() { + super(24000); + } + async captureFrame(f: AudioFrame): Promise { + await super.captureFrame(f); + if (!this.captured) { + this.captured = true; + this.onFirstFrameCaptured?.(); + } + } + // The remote avatar reports playback start well after frames were forwarded. + notifyPlaybackStarted(): void { + this.onPlaybackStarted(Date.now()); + } + flush(): void { + super.flush(); + } + clearBuffer(): void { + this.onPlaybackFinished({ playbackPosition: this.playbackPosition, interrupted: true }); + } +} + +// Mimics ParticipantAudioOutput's pause gate (room_io/_output.ts): a frame +// forwarded while the output is paused awaits the gate and BAILS on interruption +// before `super.captureFrame` counts the segment (#1662). `forwardAudio` sets +// `startedForwardingAt` before awaiting captureFrame, so "forwarding started" +// must not count as playback evidence — nothing of this segment was captured. +// `clearBuffer` releases gated frames without reporting a playback event (like +// the real output when no segment is pending), leaving the PREVIOUS segment's +// lastPlaybackEvent as what waitForPlayout returns. +class PausedGateOutput extends AudioOutput { + onGateBlocked?: () => void; + private gateFut: Future | null = null; + private interruptedFut = new Future(); + constructor() { + super(24000); + } + pause(): void { + this.gateFut = new Future(); + } + async captureFrame(f: AudioFrame): Promise { + if (this.gateFut && !this.gateFut.done) { + this.onGateBlocked?.(); + // Neither future is ever rejected in this test; catch satisfies throws-check. + await Promise.race([this.gateFut.await, this.interruptedFut.await]).catch(() => {}); + if (this.interruptedFut.done) { + return; + } + } + await super.captureFrame(f); + } + flush(): void { + super.flush(); + } + clearBuffer(): void { + this.interruptedFut.resolve(); + } +} + // Agent that synthesizes a few real frames for whatever text it receives, so the // audio path produces a first frame (no TTS provider needed). class FrameAgent extends Agent { @@ -58,6 +127,24 @@ class FrameAgent extends Agent { } } +// Agent whose TTS produces no frames and stays open long enough that an +// interruption (anchored to ttsNode being invoked, fired well before the +// close) always lands mid-forwarding with zero audio captured for the segment. +class NoFrameAgent extends Agent { + onTtsStarted?: () => void; + constructor() { + super({ instructions: 'test' }); + } + async ttsNode(): Promise | null> { + this.onTtsStarted?.(); + return new ReadableStream({ + start(controller) { + setTimeout(() => controller.close(), 500); + }, + }); + } +} + describe('AgentActivity interrupted-speech commit', () => { initializeLogger({ pretty: false, level: 'silent' }); @@ -97,4 +184,182 @@ describe('AgentActivity interrupted-speech commit', () => { await session.close(); } }); + + it('commits an interrupted reply when playback start is reported after forwarding completes (avatar output)', async () => { + const session = new AgentSession({ + llm: new FakeLLM([{ input: 'hello', content: 'A fairly long spoken reply.' }]), + }); + const audioOut = new DeferredStartOutput(); + session.output.audio = audioOut; + + // Simulate the avatar pipeline: playback starts (RPC arrives) shortly after + // the frames were forwarded, then the user interrupts mid-playback. + audioOut.onFirstFrameCaptured = () => { + setTimeout(() => { + audioOut.playbackPosition = 0.12; + audioOut.notifyPlaybackStarted(); + setTimeout(() => session.interrupt({ force: true }), 50); + }, 100); + }; + + const assistantMessages: { content: string; interrupted: boolean }[] = []; + session.on(AgentSessionEventTypes.ConversationItemAdded, (ev: ConversationItemAddedEvent) => { + if (ev.item.type === 'message' && ev.item.role === 'assistant') { + assistantMessages.push({ + content: ev.item.textContent ?? '', + interrupted: !!ev.item.interrupted, + }); + } + }); + + await session.start({ agent: new FrameAgent() }); + try { + const handle = session.generateReply({ userInput: 'hello' }); + await handle.waitForPlayout(); + await vi.waitFor(() => expect(assistantMessages.length).toBeGreaterThan(0)); + + // Pre-fix, forwardAudio rejected firstFrameFut the moment forwarding + // finished (before the deferred playback-started notification), so the + // audibly-played reply was classified "skipped" and silently dropped from + // the chat context (phantom utterance). + const msg = assistantMessages[0]!; + expect(msg.interrupted).toBe(true); + expect(msg.content.length).toBeGreaterThan(0); + expect('A fairly long spoken reply.'.startsWith(msg.content)).toBe(true); + } finally { + await session.close(); + } + }); + + it('commits an interrupted reply when only a playback position is reported (no playback-started signal)', async () => { + const session = new AgentSession({ + llm: new FakeLLM([{ input: 'hello', content: 'A fairly long spoken reply.' }]), + }); + const audioOut = new DeferredStartOutput(); + session.output.audio = audioOut; + + // The remote avatar never reports playback-started (or the RPC races with + // the interruption), but its playback-finished response carries a non-zero + // position — proof the user heard part of the reply. + audioOut.onFirstFrameCaptured = () => { + setTimeout(() => { + audioOut.playbackPosition = 0.25; + session.interrupt({ force: true }); + }, 100); + }; + + const assistantMessages: { content: string; interrupted: boolean }[] = []; + session.on(AgentSessionEventTypes.ConversationItemAdded, (ev: ConversationItemAddedEvent) => { + if (ev.item.type === 'message' && ev.item.role === 'assistant') { + assistantMessages.push({ + content: ev.item.textContent ?? '', + interrupted: !!ev.item.interrupted, + }); + } + }); + + await session.start({ agent: new FrameAgent() }); + try { + const handle = session.generateReply({ userInput: 'hello' }); + await handle.waitForPlayout(); + await vi.waitFor(() => expect(assistantMessages.length).toBeGreaterThan(0)); + + const msg = assistantMessages[0]!; + expect(msg.interrupted).toBe(true); + expect(msg.content.length).toBeGreaterThan(0); + expect('A fairly long spoken reply.'.startsWith(msg.content)).toBe(true); + } finally { + await session.close(); + } + }); + + it('does not commit an interrupted reply that forwarded no audio when a stale playback position exists', async () => { + const session = new AgentSession({ + llm: new FakeLLM([{ input: 'hello', content: 'A reply that was never spoken.' }]), + }); + const audioOut = new DeferredStartOutput(); + session.output.audio = audioOut; + + // A previously played segment leaves a non-zero lastPlaybackEvent behind. + // waitForPlayout returns it immediately for a segment that captured no + // frames — the playback position must not be attributed to that segment. + await audioOut.captureFrame(frame()); + audioOut.flush(); + audioOut.onPlaybackFinished({ playbackPosition: 0.5, interrupted: false }); + + const assistantMessages: { content: string; interrupted: boolean }[] = []; + session.on(AgentSessionEventTypes.ConversationItemAdded, (ev: ConversationItemAddedEvent) => { + if (ev.item.type === 'message' && ev.item.role === 'assistant') { + assistantMessages.push({ + content: ev.item.textContent ?? '', + interrupted: !!ev.item.interrupted, + }); + } + }); + + const agent = new NoFrameAgent(); + // Anchor the interruption to TTS starting, so it always lands while the + // segment is mid-forwarding (zero frames captured, stream still open). + agent.onTtsStarted = () => setTimeout(() => session.interrupt({ force: true }), 150); + + await session.start({ agent }); + try { + const handle = session.generateReply({ userInput: 'hello' }); + await handle.waitForPlayout(); + + // Close drains the reply task fully — the interrupted-commit block (if + // it were to run) has fired by the time close resolves. Nothing was + // heard: the reply must not be committed on the strength of the stale + // playback position. + await session.close(); + expect(assistantMessages).toHaveLength(0); + } finally { + await session.close(); + } + }); + + it('does not commit a reply whose first frame bailed at a pause gate (stale playback position)', async () => { + const session = new AgentSession({ + llm: new FakeLLM([{ input: 'hello', content: 'A reply that was never spoken.' }]), + }); + const audioOut = new PausedGateOutput(); + session.output.audio = audioOut; + + // A previously played segment leaves a non-zero lastPlaybackEvent behind. + await audioOut.captureFrame(frame()); + audioOut.flush(); + audioOut.onPlaybackFinished({ playbackPosition: 0.5, interrupted: false }); + + // The output is paused (false-interruption pause during the thinking state): + // the reply's first frame will block at the gate, never reaching + // super.captureFrame — so the segment count is never bumped and waitForPlayout + // returns the stale event above. Forwarding DID start (`startedForwardingAt` + // is set), which is exactly why forwarding-started must not gate the commit. + audioOut.pause(); + // A genuine interruption arrives while the frame is blocked at the gate. + audioOut.onGateBlocked = () => session.interrupt({ force: true }); + + const assistantMessages: { content: string; interrupted: boolean }[] = []; + session.on(AgentSessionEventTypes.ConversationItemAdded, (ev: ConversationItemAddedEvent) => { + if (ev.item.type === 'message' && ev.item.role === 'assistant') { + assistantMessages.push({ + content: ev.item.textContent ?? '', + interrupted: !!ev.item.interrupted, + }); + } + }); + + await session.start({ agent: new FrameAgent() }); + try { + const handle = session.generateReply({ userInput: 'hello' }); + await handle.waitForPlayout(); + + // Nothing of this reply was captured, let alone played: the stale 0.5s + // position from the previous segment must not commit it as 'partial'. + await session.close(); + expect(assistantMessages).toHaveLength(0); + } finally { + await session.close(); + } + }, 15_000); }); diff --git a/agents/src/voice/generation.ts b/agents/src/voice/generation.ts index 3d6a4c831..303eb057b 100644 --- a/agents/src/voice/generation.ts +++ b/agents/src/voice/generation.ts @@ -844,6 +844,25 @@ export interface _AudioOut { * metric. */ startedForwardingAt?: number; + /** + * Whether this segment has captured at least one of its own frames. Read by the + * PLAYBACK_STARTED listener registered in `performAudioForwarding` to ignore a + * stray event emitted by another overlapping segment before this one has played. + * @internal + */ + _hasCapturedOwnFrame: boolean; + /** + * The output's monotonic segment count (`capturedPlayoutSegments`) when forwarding + * was set up. The interrupted-commit gate compares the current count against this + * baseline: a bump proves a frame of THIS segment made it through + * `AudioOutput.captureFrame` — the same condition under which `waitForPlayout()` + * waits for this segment's playback event instead of returning a stale one — so + * the reported playback position can be trusted as evidence of partial playback. + * (`startedForwardingAt` is set *before* `captureFrame` resolves and is therefore + * not usable as capture evidence; a frame can bail at a pause/interrupt gate, + * e.g. `ParticipantAudioOutput`, without ever being counted.) + */ + capturedSegmentsBefore: number; } /** @@ -873,25 +892,7 @@ async function forwardAudio( const reader = ttsStream.getReader(); let resampler: AudioResampler | null = null; - // The audio output is shared across overlapping segments. When a speech is - // interrupted, the main loop immediately authorizes the next speech, so this - // forwarder can register its listener while the interrupted segment's teardown - // is still emitting PLAYBACK_STARTED on the same output. Only honor the event - // once this loop has captured its own first frame, so a stray event from - // another segment can't resolve our `firstFrameFut` prematurely. A premature - // resolution skips resampler creation (gated on `!firstFrameFut.done`) and - // pushes an unresampled frame to the AudioSource, raising - // `RtcError: sample_rate and num_channels don't match`. - let hasCapturedOwnFrame = false; - - const onPlaybackStarted = (ev: { createdAt: number }) => { - if (hasCapturedOwnFrame && !out.firstFrameFut.done) { - out.firstFrameFut.resolve(ev.createdAt); - } - }; - try { - audioOutput.on(AudioOutput.EVENT_PLAYBACK_STARTED, onPlaybackStarted); audioOutput.resume(); while (true) { @@ -912,8 +913,9 @@ async function forwardAudio( } // Mark before capturing so the PLAYBACK_STARTED emitted synchronously inside - // the first captureFrame is attributed to this segment. - hasCapturedOwnFrame = true; + // the first captureFrame is attributed to this segment (see the listener in + // `performAudioForwarding`). + out._hasCapturedOwnFrame = true; if (resampler) { for (const f of resampler.push(frame)) { @@ -936,12 +938,24 @@ async function forwardAudio( throw e; } } finally { - audioOutput.off(AudioOutput.EVENT_PLAYBACK_STARTED, onPlaybackStarted); - - if (!out.firstFrameFut.done) { - out.firstFrameFut.reject(new Error('audio forwarding cancelled before playback started')); - } - + // NOTE: `firstFrameFut` is intentionally NOT settled here. Forwarding completes + // as soon as all TTS frames are *captured*, which can be long before playback + // begins: + // - DataStream avatar outputs (`waitPlaybackStart: true`, e.g. LemonSlice) + // accept frames faster than real time and only send the + // `lk.playback_started` RPC once the avatar worker actually starts playing, + // typically ~1s after forwarding has finished (#1960). + // - A speech paused in the thinking state (`resumeFalseInterruption`) buffers + // its frames; playback starts only once the output resumes, possibly after + // this task has finished (#1909). + // Rejecting the future here dropped those late playback-started events on the + // floor: the agent never entered the "speaking" state and an interrupted reply + // was classified "skipped" and silently removed from the chat context (phantom + // utterance). Mirror the python implementation instead: the PLAYBACK_STARTED + // listener registered in `performAudioForwarding` outlives this task and + // resolves the future when the late first frame plays; the reply tasks settle + // any future still pending once the playout window ends, bounding the + // listener's lifetime. reader?.releaseLock(); audioOutput.flush(); if (signal?.aborted) { @@ -960,7 +974,32 @@ export function performAudioForwarding( const out: _AudioOut = { audio: [], firstFrameFut: new Future(), + _hasCapturedOwnFrame: false, + capturedSegmentsBefore: audioOutput.capturedPlayoutSegments, + }; + + // Resolve `firstFrameFut` from the output's PLAYBACK_STARTED event. Registered + // here (rather than inside `forwardAudio`) so the listener outlives the + // forwarding task: frames may be captured into a paused or remote-buffered + // output and only start playing after forwarding has finished (#1909, #1960). + const onPlaybackStarted = (ev: { createdAt: number }) => { + // The audio output is shared across overlapping segments. Only honor the + // event once this segment has captured its own first frame, so a stray event + // from another segment can't resolve our `firstFrameFut` prematurely. A + // premature resolution skips resampler creation (gated on + // `!firstFrameFut.done`) and pushes an unresampled frame to the AudioSource, + // raising `RtcError: sample_rate and num_channels don't match`. + if (out._hasCapturedOwnFrame && !out.firstFrameFut.done) { + out.firstFrameFut.resolve(ev.createdAt); + } }; + audioOutput.on(AudioOutput.EVENT_PLAYBACK_STARTED, onPlaybackStarted); + // Remove the listener once the future settles — resolved by playback above, or + // rejected by the reply task (via `settleFirstFrameFut`) after playout finishes + // or is interrupted without a frame ever playing. + const removeListener = () => + audioOutput.off(AudioOutput.EVENT_PLAYBACK_STARTED, onPlaybackStarted); + out.firstFrameFut.await.then(removeListener).catch(removeListener); return [ Task.from( diff --git a/agents/src/voice/generation_interrupt_before_first_frame.test.ts b/agents/src/voice/generation_interrupt_before_first_frame.test.ts new file mode 100644 index 000000000..f9331552f --- /dev/null +++ b/agents/src/voice/generation_interrupt_before_first_frame.test.ts @@ -0,0 +1,239 @@ +// SPDX-FileCopyrightText: 2026 LiveKit, Inc. +// +// SPDX-License-Identifier: Apache-2.0 + +/** + * Regression tests for livekit/agents-js#1909 (JS port of livekit/agents#5038/#5039). + * + * When the agent is in the "thinking" state and the user makes a brief sound + * *before the first TTS audio frame has played*, `AgentActivity.onStartOfSpeech` + * pauses the (not-yet-playing) speech. The TTS frames are still captured into the + * paused output buffer and the forwarding task finishes — but playback has not + * started yet, so `firstFrameFut` is still unresolved when the task ends. + * + * The bug: `forwardAudio` used to *reject* `firstFrameFut` (and remove its + * PLAYBACK_STARTED listener) in its `finally` block whenever no frame had played. + * So when the false interruption cleared and the output resumed, the buffered first + * frame played but nothing was listening — `firstFrameFut` stayed rejected forever. + * The reply task gates transcript preservation on + * `firstFrameFut.done && !firstFrameFut.rejected`, so the resumed turn was dropped + * from history even though audio reached the user. + * + * The fix moves the PLAYBACK_STARTED listener to `performAudioForwarding` (so it + * outlives the forwarding task) and stops settling the future in `forwardAudio`; + * the reply task settles it (`AgentActivity.settleFirstFrameFut`) after the playout + * window ends. A late first frame — false-interruption resume (#1909) or a remote + * avatar's deferred `lk.playback_started` RPC (#1960) — can therefore still resolve + * the future and keep the turn. + * + * NOTE: in the JS `Future`, "cancel" is `reject` (it sets `rejected = true`), so a + * literal transcription of #5039 would not have changed the `!rejected` gate — these + * tests assert on `rejected`/`done` directly to lock in the corrected behavior. + */ +import { AudioFrame } from '@livekit/rtc-node'; +import { ReadableStream } from 'stream/web'; +import { describe, expect, it } from 'vitest'; +import { initializeLogger } from '../log.js'; +import type { _AudioOut } from './generation.js'; +import { performAudioForwarding } from './generation.js'; +import { AudioOutput } from './io.js'; + +function createSilentFrame(sampleRate = 24000, channels = 1, durationMs = 20): AudioFrame { + const samplesPerChannel = Math.floor((sampleRate * durationMs) / 1000); + const data = new Int16Array(samplesPerChannel * channels); + return new AudioFrame(data, sampleRate, channels, samplesPerChannel); +} + +/** + * Mock output that models a real audio sink's pause semantics: while paused, frames + * are buffered but PLAYBACK_STARTED is NOT emitted; it fires only once the first + * frame actually plays (on the first un-paused capture, or when a paused buffer is + * resumed). `clearBuffer` drops buffered frames (a real interruption). + */ +class PausableMockAudioOutput extends AudioOutput { + capturedFrames: AudioFrame[] = []; + clearBufferCalls = 0; + private paused = false; + private startedPlaying = false; + + constructor() { + super(24000, undefined, { pause: true }); + } + + async captureFrame(frame: AudioFrame): Promise { + await super.captureFrame(frame); + this.capturedFrames.push(frame); + if (!this.paused) { + this.maybeStartPlayback(); + } + } + + pause(): void { + this.paused = true; + } + + resume(): void { + const wasPaused = this.paused; + this.paused = false; + // On resume, a buffered (but never-played) first frame begins playing. + if (wasPaused && this.capturedFrames.length > 0) { + this.maybeStartPlayback(); + } + } + + clearBuffer(): void { + this.clearBufferCalls++; + this.capturedFrames = []; + } + + private maybeStartPlayback(): void { + if (!this.startedPlaying) { + this.startedPlaying = true; + this.onPlaybackStarted(Date.now()); + } + } +} + +/** + * Mirrors the gate used by the reply tasks in `agent_activity.ts` to decide whether + * the synchronized transcript (i.e. the turn) is preserved after an interruption. + */ +function wouldPreserveTranscript(audioOut: _AudioOut): boolean { + return audioOut.firstFrameFut.done && !audioOut.firstFrameFut.rejected; +} + +describe('interruption before the first audio frame (#1909)', () => { + initializeLogger({ pretty: false, level: 'silent' }); + + it('resumes and plays a speech paused before its first frame (false interruption)', async () => { + // A controlled stream so we can pause the output *after* forwardAudio has + // started (and called its initial resume()) but before any frame is read. + let enqueue!: (frame: AudioFrame) => void; + let close!: () => void; + const stream = new ReadableStream({ + start(controller) { + enqueue = (frame) => controller.enqueue(frame); + close = () => controller.close(); + }, + }); + + const audioOutput = new PausableMockAudioOutput(); + const controller = new AbortController(); + const [task, audioOut] = performAudioForwarding(stream, audioOutput, controller); + + // User barges in during the thinking state, before the first frame has played. + audioOutput.pause(); + + // TTS frames arrive and are captured into the paused buffer; the forwarding + // task then finishes (TTS stream closed) while playback has not started. + enqueue(createSilentFrame()); + enqueue(createSilentFrame()); + close(); + await task.result; + + expect(audioOutput.capturedFrames.length).toBe(2); + // The discriminating assertion: on `main`, forwardAudio's finally rejected the + // future here, dropping the turn. The fix leaves it pending until playback. + expect(audioOut.firstFrameFut.rejected).toBe(false); + expect(audioOut.firstFrameFut.done).toBe(false); + + // The false interruption clears: the output resumes and the buffered first + // frame finally plays. + audioOutput.resume(); + const startedAt = await audioOut.firstFrameFut.await; + + expect(typeof startedAt).toBe('number'); + expect(audioOut.firstFrameFut.done).toBe(true); + expect(audioOut.firstFrameFut.rejected).toBe(false); + // The reply task would keep the (full) turn instead of blanking it. + expect(wouldPreserveTranscript(audioOut)).toBe(true); + }); + + it('keeps the partial transcript on a genuine interruption after a resume', async () => { + let enqueue!: (frame: AudioFrame) => void; + let close!: () => void; + const stream = new ReadableStream({ + start(controller) { + enqueue = (frame) => controller.enqueue(frame); + close = () => controller.close(); + }, + }); + + const audioOutput = new PausableMockAudioOutput(); + const controller = new AbortController(); + const [task, audioOut] = performAudioForwarding(stream, audioOutput, controller); + + // Paused in the thinking state before the first frame; frames buffer. + audioOutput.pause(); + enqueue(createSilentFrame()); + enqueue(createSilentFrame()); + close(); + await task.result; + + expect(audioOut.firstFrameFut.rejected).toBe(false); + + // The pause clears and playback starts (firstFrameFut resolves)... + audioOutput.resume(); + await audioOut.firstFrameFut.await; + + // ...then the user genuinely interrupts mid-playback: the reply task clears the + // buffer and evaluates its gate. + audioOutput.clearBuffer(); + expect(audioOutput.clearBufferCalls).toBe(1); + + // The turn is NOT silently lost: a frame did play, so the gate preserves the + // synchronized (partial) transcript. On `main` the future was already rejected + // during the paused finish, so this gate would be false and the turn dropped. + expect(wouldPreserveTranscript(audioOut)).toBe(true); + + // Caller-side cleanup (mirrors AgentActivity.settleFirstFrameFut) is a no-op + // here because the future already resolved. + expect(audioOut.firstFrameFut.done).toBe(true); + expect(audioOut.firstFrameFut.rejected).toBe(false); + }); + + it('detaches the PLAYBACK_STARTED listener once firstFrameFut settles', async () => { + // The listener now outlives the forwarding task, so its removal is tied to the + // future settling — resolved by playback, or rejected by the caller when the + // playout window ends (AgentActivity.settleFirstFrameFut). Both paths must + // return the shared output to zero listeners, or repeated turns would leak. + const makeStream = (frames: AudioFrame[]) => + new ReadableStream({ + start(controller) { + frames.forEach((f) => controller.enqueue(f)); + controller.close(); + }, + }); + + const audioOutput = new PausableMockAudioOutput(); + const baseline = audioOutput.listenerCount(AudioOutput.EVENT_PLAYBACK_STARTED); + + // Resolve path: the frame plays, firstFrameFut resolves. + const [task1, audioOut1] = performAudioForwarding( + makeStream([createSilentFrame()]), + audioOutput, + new AbortController(), + ); + expect(audioOutput.listenerCount(AudioOutput.EVENT_PLAYBACK_STARTED)).toBe(baseline + 1); + await task1.result; + await audioOut1.firstFrameFut.await; + // Listener removal is scheduled on the future's microtask chain. + await new Promise((resolve) => setImmediate(resolve)); + expect(audioOutput.listenerCount(AudioOutput.EVENT_PLAYBACK_STARTED)).toBe(baseline); + + // Reject path: nothing ever plays; the caller settles the future after playout. + audioOutput.pause(); + const [task2, audioOut2] = performAudioForwarding( + makeStream([]), + audioOutput, + new AbortController(), + ); + expect(audioOutput.listenerCount(AudioOutput.EVENT_PLAYBACK_STARTED)).toBe(baseline + 1); + await task2.result; + expect(audioOut2.firstFrameFut.done).toBe(false); + audioOut2.firstFrameFut.await.catch(() => {}); + audioOut2.firstFrameFut.reject(new Error('playout finished before playback started')); + await new Promise((resolve) => setImmediate(resolve)); + expect(audioOutput.listenerCount(AudioOutput.EVENT_PLAYBACK_STARTED)).toBe(baseline); + }); +}); diff --git a/agents/src/voice/generation_tts_timeout.test.ts b/agents/src/voice/generation_tts_timeout.test.ts index 5cb3803f9..e353aa54a 100644 --- a/agents/src/voice/generation_tts_timeout.test.ts +++ b/agents/src/voice/generation_tts_timeout.test.ts @@ -115,9 +115,6 @@ describe('TTS stream idle timeout', () => { const controller = new AbortController(); const [task, audioOut] = performAudioForwarding(stalledStream, audioOutput, controller, 500); - // Reject path is expected (no first frame ever captured). - audioOut.firstFrameFut.await.catch(() => {}); - vi.useFakeTimers(); // Stray PLAYBACK_STARTED before this segment captures anything must be ignored. @@ -131,7 +128,12 @@ describe('TTS stream idle timeout', () => { vi.useRealTimers(); expect(audioOutput.capturedFrames.length).toBe(0); - expect(audioOut.firstFrameFut.rejected).toBe(true); + // Forwarding ended without capturing a frame. The future stays pending — + // playback-started may legitimately arrive after forwarding completes + // (deferred avatar notification), so the caller settles it when the + // segment's playout window ends. Stray events must still be ignored. + audioOutput.onPlaybackStarted(Date.now()); + expect(audioOut.firstFrameFut.done).toBe(false); }); it('resamples a rate-mismatched frame even after a stray PLAYBACK_STARTED', async () => {