Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

"Conversation already has an active response" error with MultimodalAgent #1056

Open
davidzhao opened this issue Nov 8, 2024 · 31 comments
Open
Assignees
Labels
bug Something isn't working

Comments

@davidzhao
Copy link
Member

We've gotten reports in Slack that when certain function calls are used with MultimodalAgent, it would sometimes error out with:

2024-11-07 17:14:37,898 - ERROR livekit.plugins.openai.realtime - OpenAI S2S error {'type': 'error', 'event_id': 'event_AR7s53avu18NBq2Lk5O4r', 'error': {'type': 'invalid_request_error', 'code': None, 'message': 'Conversation already has an active response', 'param': None, 'event_id': None}} {"session_id": "sess_AR7r1ss6nsPVlPETCgFxi"}

It'd be great if anyone could produce a path to reproducing the error.

@davidzhao davidzhao added the bug Something isn't working label Nov 8, 2024
@yepher
Copy link

yepher commented Nov 20, 2024

I've been getting this error quite a bit recently. I feel like it happens more when I give a pretty long-winded response to the LLM.

@rpiacquadioryz
Copy link

rpiacquadioryz commented Dec 4, 2024

Hey Guys! just got the same error

I have implemented a function to switch the prompt. In my use case the prompt is so long that I'm trying to split it into several files. So at some point of the first prompt I call the action to switch to the following one, and then I do the same thing in the second prompt.

Here's the snippet:


class PromptManager:
    def __init__(self):
        self.current_agent = 1
        self.max_agents = 5
        self.prompts = {}
        self._load_prompts()
    
    def _load_prompts(self):
        """Load all prompt files"""
        for i in range(1, self.max_agents + 1):
            try:
                with open(f'prompts/prompt_{i}.txt', 'r', encoding='utf-8') as f:
                    self.prompts[f'prompt_{i}'] = f.read().strip()
            except Exception as e:
                print(f"Error loading prompt_{i}: {e}")
    
    def get_current_prompt(self) -> str:
        """Get the current prompt text"""
        logger.info(f"Getting current prompt: {self.current_agent}")
        prompt_key = f'prompt_{self.current_agent}'
        return self.prompts.get(prompt_key, '')
    
    def move_to_next_agent(self) -> bool:
        """Move to next agent if possible"""
        logger.info(f"Moving to next agent: {self.current_agent}")
        if self.current_agent < self.max_agents:
            self.current_agent += 1
            return True
        return False
    
    def get_current_agent_number(self) -> int:
        return self.current_agent
    
    def reset(self):
        """Reset to first agent"""
        self.current_agent = 1


prompt_manager = PromptManager()

// first define a class that inherits from llm.FunctionContext

class AssistantFnc(llm.FunctionContext):
    # the llm.ai_callable decorator marks this function as a tool available to the LLM
    # by default, it'll use the docstring as the function's description
    @llm.ai_callable()
    async def change_prompt(
        self,
        # by using the Annotated type, arg description and type are available to the LLM
        location: Annotated[
            str, llm.TypeInfo(description="Called when the user asks to change the prompt.")
        ],
    ):
        """Called when the user asks to change the prompt."""
        logger.info(f"Changing prompt to...")
        prompt_manager.move_to_next_agent()
        return prompt_manager.get_current_prompt()
 
{"message": "unhandled exception while running the job task\nTraceback (most recent call last):\n  File \"/home/ec2-user/my_project/livekit-sip-python/agent.py\", line 85, in entrypoint\n    await assistant.start(ctx.room)\nTypeError: object NoneType can't be used in 'await' expression", "level": "ERROR", "name": "livekit.agents", "pid": 479963, "job_id": "AJ_r8Z5BvTBvbsS", "timestamp": "2024-12-04T19:55:27.428705+00:00"}
{"message": "initializing process", "level": "INFO", "name": "livekit.agents", "pid": 480013, "timestamp": "2024-12-04T19:55:28.056576+00:00"}
{"message": "process initialized", "level": "INFO", "name": "livekit.agents", "pid": 480013, "timestamp": "2024-12-04T19:55:28.056635+00:00"}
2024-12-04 19:58:27.588 | INFO     | __mp_main__:change_prompt:27 - Changing prompt to...
2024-12-04 19:58:27.588 | INFO     | prompt_manager:move_to_next_agent:27 - Moving to next agent: 1
2024-12-04 19:58:27.588 | INFO     | prompt_manager:get_current_prompt:21 - Getting current prompt: 2
{"message": "OpenAI S2S error {'type': 'error', 'event_id': 'event_Aapnwr6ZXovHf5dUMg6RV', 'error': {'type': 'invalid_request_error', 'code': None, 'message': 'Conversation already has an active response', 'param': None, 'event_id': None}}", "level": "ERROR", "name": "livekit.plugins.openai.realtime", "session_id": "sess_Aapl1XChzaTlQhzuLNd1T", "pid": 479963, "job_id": "AJ_r8Z5BvTBvbsS", "timestamp": "2024-12-04T19:58:28.429702+00:00"}

when I asked chatgpt it says:

"The main issue seems to be that an attempt was made to switch prompts/agents while there was an active response in progress. OpenAI does not allow starting a new response while a conversation is still ongoing."

@nbrustein
Copy link
Contributor

nbrustein commented Dec 9, 2024

I'm getting this error, too. It seems to be happening right after a functional call tells the agent what to do next. Here is the function I have:

    @llm.ai_callable()
    async def get_topic(self):
        """Called when you need a new topic to review with the student."""
        # find the first topic that hasn't been reviewed yet
        topic = next((t for t in self.topics if not t["reviewed"]), None)
        if topic:
            topic['reviewed'] = True
            val = f"""Topic starting question: "{topic['question']}". Topic summary: {topic['summary']}"""
            logger.info(f"New topic: {val}")
            return val

        logger.info("Everything is reviewed. The student is all done.")
        return "Everything is reviewed. The student is all done."

In the meantime, how would I recover from this error? The agent just stops talking. How do I detect the issue and get the agent going again?

@rpiacquadioryz
Copy link

Hi Nate, same thing here. Once the error happens, if you speak again, does the LLM start talking again?

@yepher
Copy link

yepher commented Dec 10, 2024

@nbrustein
Copy link
Contributor

@longcw
Copy link
Collaborator

longcw commented Dec 10, 2024

@nbrustein Can you share me a simple example to reproduce this error, maybe an agent with some mock function calls?

I think can track if there is an in-progress response then either wait for or cancel it (with https://platform.openai.com/docs/api-reference/realtime-client-events/response/cancel). cc @davidzhao

@nbrustein
Copy link
Contributor

This does it pretty reliably for me. Probably about 50% of the function calls result in the error.

from __future__ import annotations
import uuid

import logging
from dotenv import load_dotenv
load_dotenv(dotenv_path=".env.local")

from typing import Annotated
from livekit import rtc
from livekit.agents import (
    AutoSubscribe,
    JobContext,
    WorkerOptions,
    cli,
    llm,
)
from livekit.agents.multimodal import MultimodalAgent
from livekit.plugins import openai


logger = logging.getLogger("my-worker")
logger.setLevel(logging.INFO)

topics = [
    {
        "question": "Why do you think it's important to summarize data using measures like mean, median, and mode instead of listing all data points?",
        "summary": "Descriptive statistics simplify large datasets by summarizing them with key numbers. Measures of central tendency—mean, median, and mode—help identify the central value of a dataset. The mean provides the average, sensitive to outliers; the median is the middle value, unaffected by extreme values; and the mode identifies the most frequent value. These measures are distinct and chosen based on the data's nature and purpose."
    },
    {
        "question": "How can outliers affect the calculation and interpretation of the mean in a dataset?",
        "summary": "The mean is calculated by summing all data values and dividing by their count. While it is a valuable measure of central tendency, it is sensitive to outliers, which can skew results. For instance, adding a single high value to a dataset can disproportionately increase the mean, making it less representative of the majority."
    },
    {
        "question": "When comparing datasets with outliers, why might the median be a better representation of the center than the mean?",
        "summary": "The median represents the middle value when data is sorted. It splits the dataset into two equal halves and remains unaffected by extreme values. This makes it a reliable measure for datasets with significant outliers, providing a clearer view of the central tendency."
    },
    {
        "question": "Can you think of situations where the mode is more useful than the mean or median?",
        "summary": "The mode identifies the most frequently occurring value in a dataset. It is particularly useful in qualitative data or when assessing popularity. Data can have multiple modes (bimodal, multimodal), showing several frequently occurring values, offering insights into distribution patterns not revealed by the mean or median."
    },
    {
        "question": "What does it mean for a dataset to have a low or high standard deviation, and why is this important?",
        "summary": "Standard deviation measures how much data values deviate from the mean. A low standard deviation indicates tightly clustered data, while a high standard deviation suggests more spread. This measure is crucial for understanding variability and consistency within a dataset, impacting interpretations in areas like quality control and risk assessment."
    },
    {
        "question": "How does the five number summary provide a comprehensive overview of a dataset?",
        "summary": "The five number summary includes the minimum, first quartile, median, third quartile, and maximum. It divides data into four parts, each containing 25% of the data points, and provides insights into the dataset’s spread, central tendency, and distribution. Metrics like the interquartile range (IQR) highlight data concentration and outliers."
    },
    {
        "question": "What advantages do boxplots offer when comparing multiple datasets?",
        "summary": "Boxplots visually represent the five number summary, including the interquartile range and median. Whiskers highlight variability, while outliers are easily identified. They enable quick comparisons between datasets, showing differences in spread, skewness, and central tendency."
    },
    {
        "question": "How do histograms make frequency distributions easier to interpret?",
        "summary": "Histograms transform frequency distributions into visual bar charts, with bars representing data frequencies within ranges. This allows for intuitive insights into data concentration, spread, and patterns like skewness, aiding quick analysis and decision-making."
    },
    {
        "question": "How does skewness affect the relationship between the mean and median in a dataset?",
        "summary": "Skewness describes asymmetry in data distribution. In right-skewed data, the mean is pulled higher by a long tail of large values, while in left-skewed data, it is pulled lower. The median remains central, often closer to the dataset’s true middle, making it a more robust measure in skewed datasets."
    },
    {
        "question": "Can you think of a real-world scenario where understanding both the mean and standard deviation is critical?",
        "summary": "Combining measures of central tendency with variation offers a deeper understanding of datasets. For example, in quality control, the mean ensures products meet specifications, while the standard deviation ensures consistency. Together, they provide a full picture of data behavior, guiding practical decisions."
    }
]

class VoiceCoursePracticeFunctionContext(llm.FunctionContext):

    def __init__(self):

        # map topics, adding a reviewed boolean to each entry, and initializing review to False
        self.topics = [{"reviewed": False, **topic} for topic in topics]

        logger.info(f"Initialized with {len(self.topics)} topics.")
        super().__init__()

    @llm.ai_callable()
    async def get_topic(self):
        """Called when you need a new topic to review with the student."""
        # find the first topic that hasn't been reviewed yet
        topic = next((t for t in self.topics if not t["reviewed"]), None)
        if topic:
            topic['reviewed'] = True
            val = f"""Topic starting question: "{topic['question']}". Topic summary: {topic['summary']}"""
            logger.info(f"New topic: {val}")
            return val

        logger.info("Everything is reviewed. The student is all done.")
        return "Everything is reviewed. The student is all done."


async def entrypoint(ctx: JobContext):
    logger.info(f"connecting to room {ctx.room.name}")
    await ctx.connect(auto_subscribe=AutoSubscribe.AUDIO_ONLY)

    participant = await ctx.wait_for_participant()

    await run_multimodal_agent(ctx, participant)

    logger.info("agent started")

# Custom serializer for JSON encoding. FIXME move
def __custom_serializer(obj):
    if isinstance(obj, uuid.UUID):
        return str(obj)  # Convert UUID to string
    raise TypeError(f"Object of type {type(obj).__name__} is not JSON serializable")

async def run_multimodal_agent(ctx: JobContext, participant: rtc.RemoteParticipant):
    logger.info("***** starting multimodal agent %s %s %s",participant.name, participant.attributes, participant.metadata)

    instructions = (
        "You are a tutor talking to a student in a graduate degree program. The student wants to practice for "
        "an exam. You can use the provided functions to get information about a list of topics the student should review."
        "Once the student has demonstrated that they are comfortable with a topic, you can move on to the next one."
        "Don't talk too much. As long as the student seems confident with the material, ask questions more than just "
        "repeating information that they likely already know."
    )

    model = openai.realtime.RealtimeModel(
        instructions=instructions,
        modalities=["audio", "text"],
    )
    assistant = MultimodalAgent(
        model=model,
        fnc_ctx=VoiceCoursePracticeFunctionContext(),
    )
    assistant.start(ctx.room, participant)

    session = model.sessions[0]
    session.conversation.item.create(
        llm.ChatMessage(
            role="assistant",
            content='''Start off with a short intro by saying something like "Let's get started reviewing." Then use the provided function to select a topic and start reviewing.'''
        )
    )
    session.response.create()


if __name__ == "__main__":
    cli.run_app(
        WorkerOptions(
            entrypoint_fnc=entrypoint,
        )
    )

@longcw
Copy link
Collaborator

longcw commented Dec 10, 2024

Thanks @nbrustein! I was able to reproduce it and I think the root cause is that when there are more than one function calls, each of them will trigger a response request, and the later one will raise the error if the response of the first one is not finished ERROR livekit.plugins.openai.realtime - OpenAI S2S error {'type': 'error', 'event_id': 'event_AcuTysGpIANz2g1VGvdXZ', 'error': {'type': 'invalid_request_error', 'code': None, 'message': 'Conversation already has an active response', 'param': None, 'event_id': None}}.

@nbrustein
Copy link
Contributor

Great. Thanks for looking into it. Can you post the fix here whenever there is one? I'm curious to see where this gets implemented.

@longcw
Copy link
Collaborator

longcw commented Dec 10, 2024

I tried to track the activate response and provide the options to wait for cancel the in-progress response. However, I found that this error cannot be completely avoided in server_vad mode because the OAI server may create the response at any time, and we may send response.create before receiving the created event.

I suggest we cancel the "known" existing response before response.create and ignore the error if it still occurs, as it means the OAI server just created a response before we sent the request.

@longcw
Copy link
Collaborator

longcw commented Dec 10, 2024

@nbrustein In your example, the issue happened most likely because the session.response.create() in the entry point creates a function call that will also trigger a response.create, the error happens if it triggers before the first response done. This #1204 should fixed the problem.

@nbrustein
Copy link
Contributor

I understand how my session.response.create() could create a problem right at the beginning of the conversation, but would it explain why I'm hitting this issue on the 3rd or 4th function call?

Am I right in believing session.response.create() is basically sending a message telling the LLM to start talking, or am I misunderstanding what that does?

@longcw
Copy link
Collaborator

longcw commented Dec 11, 2024

I understand how my session.response.create() could create a problem right at the beginning of the conversation, but would it explain why I'm hitting this issue on the 3rd or 4th function call?

Am I right in believing session.response.create() is basically sending a message telling the LLM to start talking, or am I misunderstanding what that does?

Yes, response.create() is sending a message to the LLM to start the conversation. If there is a response in progress that is not completed, an error occurs.
I think this happens when the function is finished "too soon". In your case, the previous response triggered the function call, which then returns to the next topic and immediately calls response.create(), so the likelihood of the previous response not closing is relatively high. It's the same for first or other calls.

Tracking and canceling (or waiting for) the active response before sending the response.create after the function call should solve this problem.

@longcw longcw self-assigned this Dec 11, 2024
@simplegr33n
Copy link

simplegr33n commented Jan 3, 2025

I'm still getting this error after tool calls on livekit-plugins-openai==0.1013. Not every time but frequently enough. Dunno if these logs are useful:

QUEUE MSG: {'type': 'conversation.item.create', 'previous_item_id': 'item_AlPth1cvAa95Gnc5BfPlu', 'item': {'id': 'item_a3fa4d9d1293', 'type': 'function_call_output', 'call_id': 'call_49XkflVcjecEgaS7', 'output': 'Returning from animation_instruction'}}
2025-01-02 16:32:10,640 - INFO livekit.plugins.openai.realtime - creating response for tool call {"function": "trigger_animation", "pid": 1054, "job_id": "AJ_8gy9gkN9jm7k"}
2025-01-02 16:32:10,640 - WARNING livekit.plugins.openai.realtime - waiting for in-progress response to be done before creating a new one {"existing_response_id": "resp_AlPthVP2IrDmDfVgjxcZU", "session_id": "sess_AlPtJN7aHZU0mJxMZhmMi", "pid": 1054, "job_id": "AJ_8gy9gkN9jm7k"}
QUEUE MSG: {'type': 'response.create'}
2025-01-02 16:32:10,653 - INFO livekit.plugins.openai.realtime - in-progress response is done, creating a new one {"existing_response_id": "resp_AlPthVP2IrDmDfVgjxcZU", "session_id": "sess_AlPtJN7aHZU0mJxMZhmMi", "pid": 1054, "job_id": "AJ_8gy9gkN9jm7k"}
2025-01-02 16:32:10,693 - INFO conversation_state - [USER] Thank you. {"pid": 1054, "job_id": "AJ_8gy9gkN9jm7k"}
2025-01-02 16:32:10,694 - DEBUG livekit.agents - committed user speech {"user_transcript": "Thank you.\n", "pid": 1054, "job_id": "AJ_8gy9gkN9jm7k"}
2025-01-02 16:32:10,729 - DEBUG livekit.plugins.openai.realtime - conversation item created {"type": "conversation.item.created", "event_id": "event_AlPtiCoF8NKMMyZBJ53z9", "previous_item_id": "item_AlPth1cvAa95Gnc5BfPlu", "item": {"id": "item_a3fa4d9d1293", "object": "realtime.item", "type": "function_call_output", "call_id": "call_49XkflVcjecEgaS7", "output": "Returning from animation_instruction"}, "pid": 1054, "job_id": "AJ_8gy9gkN9jm7k"}
2025-01-02 16:32:10,752 - ERROR livekit.plugins.openai.realtime - OpenAI S2S error {'type': 'error', 'event_id': 'event_AlPtiK4C2Mv24jQ9AGp6X', 'error': {'type': 'invalid_request_error', 'code': None, 'message': 'Conversation already has an active response', 'param': None, 'event_id': None}} {"session_id": "sess_AlPtJN7aHZU0mJxMZhmMi", "pid": 1054, "job_id": "AJ_8gy9gkN9jm7k"}mation", "call_id": "call_7Vg4EkmM8ULH3xA3", "arguments": ""}, "pid": 106

@nbrustein
Copy link
Contributor

nbrustein commented Jan 3, 2025

I'm also still seeing this issue, using pretty much the same code that I pasted previously. My logs are slightly different from @simplegr33n

I don't see anything in those logs that would suggest what the in progress response is. I don't see another response being created before or during the function call.

2025-01-02 16:56:04,826 - DEBUG livekit.plugins.openai.realtime - conversation item created {"type": "conversation.item.created", "event_id": "event_AlNSemH7c44VxzgyjPiiw", "previous_item_id": "item_AlNS26noPq2bSN7HjrqnX", "item": {"id": "item_AlNSeeqWdIIakoOzXkAyx", "object": "realtime.item", "type": "message", "status": "completed", "role": "user", "content": [{"type": "input_audio", "transcript": null}]}, "pid": 52124, "job_id": "AJ_MprvZyeaGjen"}
2025-01-02 16:56:05,368 - DEBUG livekit.plugins.openai.realtime - conversation item created {"type": "conversation.item.created", "event_id": "event_AlNSfkiBCKXmIUZe1G4P2", "previous_item_id": "item_AlNSeeqWdIIakoOzXkAyx", "item": {"id": "item_AlNSeYimzPuPDLeq0SwEv", "object": "realtime.item", "type": "function_call", "status": "in_progress", "name": "get_topic", "call_id": "call_i6DaIsHEkRVYHbVN", "arguments": ""}, "pid": 52124, "job_id": "AJ_MprvZyeaGjen"}
2025-01-02 16:56:05,388 - DEBUG livekit.plugins.openai.realtime - executing ai function {"function": "get_topic", "pid": 52124, "job_id": "AJ_MprvZyeaGjen"}
2025-01-02 16:56:05,390 - INFO livekit.plugins.openai.realtime - creating response for tool call {"function": "get_topic", "pid": 52124, "job_id": "AJ_MprvZyeaGjen"}
2025-01-02 16:56:05,446 - DEBUG livekit.agents - committed user speech {"user_transcript": "Yeah.\n", "pid": 52124, "job_id": "AJ_MprvZyeaGjen"}
__on_error: RealtimeError(event_id='event_AlNSfkUZQvJqiGjSFRJwZ', type='invalid_request_error', message='Conversation already has an active response', code=None, param=None)
2025-01-02 16:56:05,467 - DEBUG livekit.plugins.openai.realtime - conversation item created {"type": "conversation.item.created", "event_id": "event_AlNSfDDHDptGuBNSbUlwy", "previous_item_id": "item_AlNSeYimzPuPDLeq0SwEv", "item": {"id": "item_3456b495ade7", "object": "realtime.item", "type": "function_call_output", "call_id": "call_i6DaIsHEkRVYHbVN", "output": "Topic starting question: \"How can outliers affect the calculation and interpretation of the mean in a dataset?\". Topic summary: The mean is calculated by summing all data values and dividing by their count. While it is a valuable measure of central tendency, it is sensitive to outliers, which can skew results. For instance, adding a single high value to a dataset can disproportionately increase the mean, making it less representative of the majority."}, "pid": 52124, "job_id": "AJ_MprvZyeaGjen"}
2025-01-02 16:56:05,467 - ERROR livekit.plugins.openai.realtime - OpenAI S2S error {'type': 'error', 'event_id': 'event_AlNSfkUZQvJqiGjSFRJwZ', 'error': {'type': 'invalid_request_error', 'code': None, 'message': 'Conversation already has an active response', 'param': None, 'event_id': None}} {"session_id": "sess_AlNQzDMFD12JGFMr4OpkP", "pid": 52124, "job_id": "AJ_MprvZyeaGjen"}

@nbrustein
Copy link
Contributor

I looked into this more deeply, but I didn't find an explanation. I don't see any issues with the way the code currently checks for an active response, but even when there is no active response in the RealtimeModel, a message created after a function call regularly triggers the "Conversation already has an active response" error.

I had some success by listening for that error and then just sending a new assistant message followed by a new response.create immediately. In most cases, the agent would respond. I guess that indicates that whatever response was active when the tool output triggered a response.create, it's not active anymore milliseconds later.

I only saw one instance where this created a loop of "Conversation already has an active response" errors triggering a new response.create, but even in that case it resolved itself after 7 quick iterations and the conversation continued.

@simplegr33n
Copy link

simplegr33n commented Jan 3, 2025

I've also dug into this a bit further to try to debug but can't really figure out the core issue. If I return None from my function call then the issue is avoided, but the agent doesn't provide a speech response with the function call until prompted again.

Attempting to set the on_duplicate parameter to "cancel_existing" instead of "keep_both" behaves well for me for a few turns, but eventually the conversation will hit a failed to handle OpenAI S2S message error:

if tool_call.content is not None:
    create_fut = self.conversation.item.create(
        tool_call,
        previous_item_id=item_id,
    )
    await self.response.create(on_duplicate="cancel_existing")
    await create_fut

error:

2025-01-03 12:07:01,773 - DEBUG livekit.plugins.openai.realtime - conversation item created {"type": "conversation.item.created", "event_id": "event_AliEfPYJZr835dS0UMB7G", "previous_item_id": "item_AliEefpsUCQ0eiKZ81KCq", "item": {"id": "item_9a233009f88f", "object": "realtime.item", "type": "function_call_output", "call_id": "call_tfhBqx7iHJGrz8Ws", "output": "Returning from animation instruction {animation_instruction}"}, "pid": 38348, "job_id": "AJ_58sjrgfVmbq8"}
2025-01-03 12:07:01,773 - ERROR livekit.plugins.openai.realtime - failed to handle OpenAI S2S message
Traceback (most recent call last):
  File "/../livekit/plugins/openai/realtime/realtime_model.py", line 1231, in _recv_task
    self._handle_response_done(data)
  File "/../livekit/plugins/openai/realtime/realtime_model.py", line 1619, in _handle_response_done
    response.done_fut.set_result(None)
asyncio.exceptions.InvalidStateError: invalid state {"websocket_message": [1, "{\"type\":\"response.done\",\"event_id\":\"event_AliEftm9XPbpDC38Nqskc\",\"response\":{\"object\":\"realtime.response\",\"id\":\"resp_AliEeVUBRhNQGLYNRwSrL\",\"status\":\"cancelled\",\"status_details\":{\"type\":\"cancelled\",\"reason\":\"client_cancelled\"},\"output\":[{\"id\":\"item_AliEefpsUCQ0eiKZ81KCq\",\"object\":\"realtime.item\",\"type\":\"function_call\",\"status\":\"completed\",\"name\":\"trigger_animation\",\"call_id\":\"call_tfhBqx7iHJGrz8Ws\",\"arguments\":\"{\\\"animation_instruction\\\":\\\"long praise\\\"}\"}],\"usage\":{\"total_tokens\":5595,\"input_tokens\":5578,\"output_tokens\":17,\"input_token_details\":{\"text_tokens\":1855,\"audio_tokens\":3723,\"cached_tokens\":5312,\"cached_tokens_details\":{\"text_tokens\":1792,\"audio_tokens\":3520}},\"output_token_details\":{\"text_tokens\":17,\"audio_tokens\":0}},\"metadata\":null}}", ""], "session_id": "sess_AliBXVO4gLpQgMjB6wYrH", "pid": 38348, "job_id": "AJ_58sjrgfVmbq8"}

@longcw
Copy link
Collaborator

longcw commented Jan 4, 2025

@simplegr33n @nbrustein Do you have an example to reproduce this issue so I can help to debug? There is a gap between the response created and we received the "event of response created". Perhaps the error was caused bc creating response between this gap. What will happen when this happened, the agent stuck or continue speaking?

@nbrustein
Copy link
Contributor

@simplegr33n @nbrustein Do you have an example to reproduce this issue so I can help to debug? There is a gap between the response created and we received the "event of response created". Perhaps the error was caused bc creating response between this gap. What will happen when this happened, the agent stuck or continue speaking?

  1. The example I posted previously still reproduces the error.
  2. When the error happens, the agent gets stuck, but sending another response.create will get it going again (see my previous comment)

Do you have a theory about what the open response is when we hit this error? It seems like it can't be the previous response that triggered the function call, because we're received a response.done for that one. But it doesn't seem like there's any other response, because if I sleep inside of the function call, it's not like the agent starts talking again or anything.

Could this be a bug inside OpenAI, rather than in the livekit-agents code?

@davidzhao davidzhao reopened this Jan 6, 2025
@longcw
Copy link
Collaborator

longcw commented Jan 8, 2025

  1. The example I posted previously still reproduces the error.
  2. When the error happens, the agent gets stuck, but sending another response.create will get it going again (see my previous comment)

Do you have a theory about what the open response is when we hit this error? It seems like it can't be the previous response that triggered the function call, because we're received a response.done for that one. But it doesn't seem like there's any other response, because if I sleep inside of the function call, it's not like the agent starts talking again or anything.

Could this be a bug inside OpenAI, rather than in the livekit-agents code?

I have tested with the example on the main branch, I can see some warnings waiting for in-progress response to be done but the conversation went well without stuck

# user speech end and ask for a next question
2025-01-08 17:42:07,942 - DEBUG livekit.plugins.openai.realtime - conversation item created {"type": "conversation.item.created", "event_id": "event_AnMq5SdC66vO7lYSNtYW2", "previous_item_id": "item_AnMpnAIIAHimrJiSx22sj", "item": {"id": "item_AnMq08uV3KmJ0CLEZvsco", "object": "realtime.item", "type": "message", "status": "completed", "role": "user", "content": [{"type": "input_audio", "transcript": null}]}, "pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
# response to trigger get_topic function (id: resp_AnMq5L3sM00rdh65xBgPP)
2025-01-08 17:42:07,950 - INFO livekit.plugins.openai.realtime - response created resp_AnMq5L3sM00rdh65xBgPP {"pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
2025-01-08 17:42:08,397 - DEBUG livekit.plugins.openai.realtime - conversation item created {"type": "conversation.item.created", "event_id": "event_AnMq6psGpXNkc4l72K5YV", "previous_item_id": "item_AnMq08uV3KmJ0CLEZvsco", "item": {"id": "item_AnMq5XhewslsZJqxyohfA", "object": "realtime.item", "type": "function_call", "status": "in_progress", "name": "get_topic", "call_id": "call_Sj950dBv4zdE0xoN", "arguments": ""}, "pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
2025-01-08 17:42:08,412 - DEBUG livekit.plugins.openai.realtime - executing ai function {"function": "get_topic", "pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
2025-01-08 17:42:08,412 - INFO my-worker - New topic: Topic starting question: "How can outliers affect the calculation and interpretation of the mean in a dataset?". Topic summary: The mean is calculated by summing all data values and dividing by their count. While it is a valuable measure of central tendency, it is sensitive to outliers, which can skew results. For instance, adding a single high value to a dataset can disproportionately increase the mean, making it less representative of the majority. {"pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
# function call finished
2025-01-08 17:42:08,412 - INFO livekit.plugins.openai.realtime - creating response for tool call {"function": "get_topic", "pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
# waiting for resp_AnMq5L3sM00rdh65xBgPP done
2025-01-08 17:42:08,412 - WARNING livekit.plugins.openai.realtime - waiting for in-progress response to be done before creating a new one {"existing_response_id": "resp_AnMq5L3sM00rdh65xBgPP", "session_id": "sess_AnMp6blwzmz7AweddYcHI", "pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
# creating a new response for next topic
2025-01-08 17:42:08,416 - INFO livekit.plugins.openai.realtime - in-progress response is done, creating a new one {"existing_response_id": "resp_AnMq5L3sM00rdh65xBgPP", "session_id": "sess_AnMp6blwzmz7AweddYcHI", "pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
# function call output was synced to the API
2025-01-08 17:42:08,673 - DEBUG livekit.plugins.openai.realtime - conversation item created {"type": "conversation.item.created", "event_id": "event_AnMq6bGHdH8YCuup9umyH", "previous_item_id": "item_AnMq5XhewslsZJqxyohfA", "item": {"id": "item_c4b13263ae86", "object": "realtime.item", "type": "function_call_output", "call_id": "call_Sj950dBv4zdE0xoN", "output": "Topic starting question: \"How can outliers affect the calculation and interpretation of the mean in a dataset?\". Topic summary: The mean is calculated by summing all data values and dividing by their count. While it is a valuable measure of central tendency, it is sensitive to outliers, which can skew results. For instance, adding a single high value to a dataset can disproportionately increase the mean, making it less representative of the majority."}, "pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}
# new response created
2025-01-08 17:42:08,674 - INFO livekit.plugins.openai.realtime - response created resp_AnMq62GEBtOUx50nMJybS {"pid": 2900269, "job_id": "AJ_vB4igeLXEbjJ"}

I added a log to the response_created event to see the ID of the response that has been created. The expected behavior is like the log above:

  1. a response is created to trigger a function call after the user has spoken
  2. the function call finishes too soon before the response finishes
  3. we wait for it to done and trigger a new response (with a warning log waiting for in-progress response to be done)

It should be helpful to log the response id of both response_created and response_done events. Most likely the error happens bc OAI API created a response and at the same time the function call wants to create another before we got the response_created event. If that's true we may see a log of the response created right after the error "Conversation already has an active response".

If this is the case, the frequency with which the error occurs may be related to network latency (the speed at which the response_created event is received) or background noise (the response may be created from background noise). But there is no way to avoid this completely if so, and one solution is for the agent to handle it internally: listen for the error and try to resend response.created after receiving the response_created event.

@nbrustein @simplegr33n it would be great if you could help to print the logs of response_created and response_done events so we can verify if it's the case. I cannot reproduce the error consistently on my side.

@nbrustein
Copy link
Contributor

I'm using the code that I pasted previously and can reproduce the error reliably every 2 or 3 function calls.

Here is an example, showing the conversation.item.created, response.created, and response.done events, function calls, and also cases where Response#create had to wait for an in-progress response before sending a new response.

In this case there were 3 function calls, with an error coming on the third one. I don't see why the 3rd function call would have triggered an error when the first one didn't. From the events, it seems like the exact same order of events.

At 2025-01-08 14:56:12,756

  • A conversation.item.created event came in for an assistant message
  • 3 ms later, a response.created event came in
  • 224ms later, a conversation.item.created came in to trigger a function call
  • Before the function started executing, a response.done event came in
  • Within a millisecond after the response.done event came in, the function call executed
  • 96 ms later the conversation.item.created resulting from the function call came in
  • 1ms later, a response.created event came in

At 2025-01-08 14:57:38,084

  • A conversation.item.created event came in for a user message
  • 16 ms later, a response.created event came in
  • 534 ms later, a conversation.item.created came in to trigger a function call
  • 11 ms later, before the response.done event came in, the function call executed. The resulting Response#create delayed creating a response until the previous response completed
  • 14 ms later, the response.done event came in, at which point a response was successfully created for the function call output

At 2025-01-08 14:58:20,282

  • A conversation.item.created event came in for a user message
  • 5 ms later, a response.created event came in
  • 578 ms later, a conversation.item.created came in to trigger a function call
  • Before the function started executing, a response.done event came in
  • Within a millisecond after the response.done event came in, the function call executed
  • 152 ms later, the conversation.item.created resulting from the function call came in
  • 236 ms later, the error event came in for "Conversation already has an active response"
2025-01-08 14:56:12,756 - conversation.item.created type=message role=assistant
2025-01-08 14:56:12,759 -  *** response.created. response_id: resp_AnWRw8HuFyA1AH3eNnjj4
2025-01-08 14:56:12,983 - conversation.item.created type=function_call role=None
2025-01-08 14:56:12,991 -  *** response.done. response_id: resp_AnWRw8HuFyA1AH3eNnjj4
2025-01-08 14:56:12,991 - Starting function call execution.
2025-01-08 14:56:12,992 - Completed function call execution.
2025-01-08 14:56:13,087 - conversation.item.created type=function_call_output role=None
2025-01-08 14:56:13,088 -  *** response.created. response_id: resp_AnWRxMXprSaBZqV8svdmL
2025-01-08 14:56:13,304 - conversation.item.created type=message role=assistant
2025-01-08 14:56:13,458 - waiting for in-progress response to be done
2025-01-08 14:56:13,468 -  *** response.done. response_id: resp_AnWRxMXprSaBZqV8svdmL
2025-01-08 14:56:13,468 - in-progress response is done, creating a new one
2025-01-08 14:56:13,516 - conversation.item.created type=message role=user
2025-01-08 14:56:13,533 -  *** response.created. response_id: resp_AnWRxiqqOYqWyD6l8phUF
2025-01-08 14:56:13,804 - conversation.item.created type=message role=assistant
2025-01-08 14:56:14,152 - waiting for in-progress response to be done
2025-01-08 14:56:14,153 -  *** response.done. response_id: resp_AnWRxiqqOYqWyD6l8phUF
2025-01-08 14:56:14,154 - in-progress response is done, creating a new one
2025-01-08 14:56:14,216 - conversation.item.created type=message role=user
2025-01-08 14:56:14,219 -  *** response.created. response_id: resp_AnWRyCQYLzEuLVeo995BG
2025-01-08 14:56:14,526 - conversation.item.created type=message role=assistant
2025-01-08 14:56:16,183 -  *** response.done. response_id: resp_AnWRyCQYLzEuLVeo995BG
2025-01-08 14:56:27,597 - conversation.item.created type=message role=user
2025-01-08 14:56:27,607 -  *** response.created. response_id: resp_AnWSBCPoO9XGkLcISjqtZ
2025-01-08 14:56:27,920 - conversation.item.created type=message role=assistant
2025-01-08 14:56:30,726 -  *** response.done. response_id: resp_AnWSBCPoO9XGkLcISjqtZ
2025-01-08 14:56:51,000 - conversation.item.created type=message role=user
2025-01-08 14:56:51,000 -  *** response.created. response_id: resp_AnWSYnHEPNkmJEyPiLCr9
2025-01-08 14:56:51,379 -  *** response.done. response_id: resp_AnWSYnHEPNkmJEyPiLCr9
2025-01-08 14:56:54,674 - conversation.item.created type=message role=user
2025-01-08 14:56:54,681 -  *** response.created. response_id: resp_AnWScYjIHdcUK8cToOSpY
2025-01-08 14:56:54,889 -  *** response.done. response_id: resp_AnWScYjIHdcUK8cToOSpY
2025-01-08 14:56:58,779 - conversation.item.created type=message role=user
2025-01-08 14:56:58,781 -  *** response.created. response_id: resp_AnWSgJ7ZM6YS0Hwz6S17T
2025-01-08 14:56:58,983 -  *** response.done. response_id: resp_AnWSgJ7ZM6YS0Hwz6S17T
2025-01-08 14:57:02,676 - conversation.item.created type=message role=user
2025-01-08 14:57:02,683 -  *** response.created. response_id: resp_AnWSkJnisqzH8Cv2JS3TY
2025-01-08 14:57:03,123 - conversation.item.created type=message role=assistant
2025-01-08 14:57:03,224 -  *** response.done. response_id: resp_AnWSkJnisqzH8Cv2JS3TY
2025-01-08 14:57:11,483 - conversation.item.created type=message role=user
2025-01-08 14:57:11,492 -  *** response.created. response_id: resp_AnWStk8iXynWakTeszGo5
2025-01-08 14:57:11,883 -  *** response.done. response_id: resp_AnWStk8iXynWakTeszGo5
2025-01-08 14:57:16,288 - conversation.item.created type=message role=user
2025-01-08 14:57:16,290 -  *** response.created. response_id: resp_AnWSy8EWNjMu5IDAcKFcY
2025-01-08 14:57:16,391 -  *** response.done. response_id: resp_AnWSy8EWNjMu5IDAcKFcY
2025-01-08 14:57:21,577 - conversation.item.created type=message role=user
2025-01-08 14:57:21,584 -  *** response.created. response_id: resp_AnWT3IC8IHrM222mgSsVl
2025-01-08 14:57:22,159 - conversation.item.created type=message role=assistant
2025-01-08 14:57:24,503 -  *** response.done. response_id: resp_AnWT3IC8IHrM222mgSsVl
2025-01-08 14:57:38,084 - conversation.item.created type=message role=user
2025-01-08 14:57:38,090 -  *** response.created. response_id: resp_AnWTKyDNaqUVH6NTvn0Tv
2025-01-08 14:57:38,624 - conversation.item.created type=function_call role=None
2025-01-08 14:57:38,635 - Starting function call execution.
2025-01-08 14:57:38,635 - Completed function call execution.
2025-01-08 14:57:38,635 - waiting for in-progress response to be done
2025-01-08 14:57:38,649 -  *** response.done. response_id: resp_AnWTKyDNaqUVH6NTvn0Tv
2025-01-08 14:57:38,650 - in-progress response is done, creating a new one
2025-01-08 14:57:38,691 - conversation.item.created type=function_call_output role=None
2025-01-08 14:57:38,712 -  *** response.created. response_id: resp_AnWTKelHKvLjIuJPZBEJQ
2025-01-08 14:57:39,190 - conversation.item.created type=message role=assistant
2025-01-08 14:57:40,509 -  *** response.done. response_id: resp_AnWTKelHKvLjIuJPZBEJQ
2025-01-08 14:57:53,884 - conversation.item.created type=message role=user
2025-01-08 14:57:53,885 -  *** response.created. response_id: resp_AnWTZQ8cSfFGyklsQq2nw
2025-01-08 14:57:53,885 -  *** response.done. response_id: resp_AnWTZQ8cSfFGyklsQq2nw
2025-01-08 14:57:55,775 - conversation.item.created type=message role=user
2025-01-08 14:57:55,784 -  *** response.created. response_id: resp_AnWTbzOplpPBAlx1Jclm4
2025-01-08 14:57:56,693 - conversation.item.created type=message role=assistant
2025-01-08 14:58:00,355 -  *** response.done. response_id: resp_AnWTbzOplpPBAlx1Jclm4
2025-01-08 14:58:20,282 - conversation.item.created type=message role=user
2025-01-08 14:58:20,287 -  *** response.created. response_id: resp_AnWU03Nqb3euznvC537gs
2025-01-08 14:58:20,865 - conversation.item.created type=function_call role=None
2025-01-08 14:58:20,890 -  *** response.done. response_id: resp_AnWU03Nqb3euznvC537gs
2025-01-08 14:58:20,890 - Starting function call execution.
2025-01-08 14:58:20,890 - Completed function call execution.
2025-01-08 14:58:20,942 - conversation.item.created type=function_call_output role=None
2025-01-08 14:58:21,178 - error. message: Conversation already has an active response

@rpiacquadioryz
Copy link

rpiacquadioryz commented Jan 8, 2025

Hey @nbrustein I was having the same error when executing the tool/function and found a way to solve it. Could you please try it and let me know if it worked for you?

Instead for making the changes inside the function I added an event listener. Now, the function returns a void, and when the event listener detects the function executed it makes the changes. So basically it's about moving the logic from inside the tool to the listener.

Here's how:

class AssistantFnc(llm.FunctionContext):
    @llm.ai_callable()
    async def change_prompt(
        self,
    ):
        """
        This function is called by the LLM to request a prompt change.
        But we do NOT change the prompt here. We just acknowledge the call.
        """
 
def setup_event_listeners(assistant):
      @assistant.on("function_calls_collected")
      def on_function_calls(fnc_call_infos: list[llm.FunctionCallInfo]):
          """
          Every time the LLM calls a function,
          we check if it is "change_prompt"
          """
          logger.info(f"Function calls: {fnc_call_infos}")
  
          for fnc_call in fnc_call_infos:
              # The name of the function is in fnc_call.name
              if fnc_call.function_info.name == "change_prompt":
                  logger.info("The LLM called the change_prompt function. Proceeding to change the prompt...")
  
                  prompt_manager.move_to_next_agent()
                  new_prompt = prompt_manager.get_current_prompt()
  
                  session = assistant._session
  
                  # 1. Create an empty context
                  empty_context = llm.ChatContext()
                  # 2. Clear the current context
                  asyncio.create_task(session.set_chat_ctx(empty_context))
                  # 3. Update the prompt
                  session.session_update(instructions=new_prompt)
  
                  logger.info(f"Context cleared and prompt updated. Now in prompt_{prompt_manager.get_current_agent_number()}")
        

async def entrypoint(ctx: JobContext):
    logger.info("starting entrypoint")

      # Ensure prompts are loaded
      if not prompt_manager.is_ready():
          await prompt_manager.initialize()
      
      # Connect to room
      await ctx.connect(auto_subscribe=AutoSubscribe.AUDIO_ONLY)
      logger.info("Connected to room")
      
      # Wait for participant
      participant = await ctx.wait_for_participant()
      logger.info(f"Participant joined: {participant.identity}")
  
      # Get initial prompt
      initial_prompt = prompt_manager.get_current_prompt()
      logger.info("Initial prompt loaded")
      # logger.info(f"Initial prompt: {initial_prompt}")
  
      # Create model with configuration
      config = read_config()
  
      assistant = await create_realtime_assistant(initial_prompt, config)
      logger.info("Created OpenAI Realtime API assistant")
  
      # Set up event listeners and start assistant
      setup_event_listeners(assistant)
      assistant.start(ctx.room)
      logger.info("Assistant started")
  
      # Keep connection alive
      while ctx.room and ctx.room.connection_state:
          await asyncio.sleep(1)

@longcw
Copy link
Collaborator

longcw commented Jan 9, 2025

@nbrustein Thanks for your testing! Can you share some more logs after the error occurs. I would like to see if there is a "response.created" message after the error "Conversation already has an active response" (if you didn't perform any action after the error) and what conversation items it has.

My assumption is that there is an response created by the realtime API right before we send the response.create request. So if that's the case we should see the logs about that response in the logs. If not, then most likely it's some unknown bug on the API side.

@longcw
Copy link
Collaborator

longcw commented Jan 9, 2025

Btw, I created a pr to support local VAD #1347 that can disable the auto response creation on the server side.

@nbrustein
Copy link
Contributor

nbrustein commented Jan 9, 2025

@nbrustein Thanks for your testing! Can you share some more logs after the error occurs. I would like to see if there is a "response.created" message after the error "Conversation already has an active response" (if you didn't perform any action after the error) and what conversation items it has.

My assumption is that there is an response created by the realtime API right before we send the response.create request. So if that's the case we should see the logs about that response in the logs. If not, then most likely it's some unknown bug on the API side.

No, after that nothing else will happen unless I start talking again to get it going. I have no idea which response it is that it's complaining about. It seems like maybe it sends the response.done but still leaves the old response active for a short time.

@nbrustein
Copy link
Contributor

@rpiacquadioryz can you try to fix up the formatting in your comment? I'm having trouble figuring out what's supposed to indented.

@rpiacquadioryz
Copy link

fixed it! @nbrustein

@longcw
Copy link
Collaborator

longcw commented Jan 10, 2025

No, after that nothing else will happen unless I start talking again to get it going. I have no idea which response it is that it's complaining about. It seems like maybe it sends the response.done but still leaves the old response active for a short time.

Ok, then I have no idea why the error happens. And it's weird that I cannot reproduce it on my end. I do see a lot of warnings like this WARNING livekit.plugins.openai.realtime - waiting for in-progress response to be done before creating a new one, have you seen such logs?

I am wondering if we cannot find a root cause, is that make sense internally we check this specific error type and try to re-send the response.create?

@davidzhao
Copy link
Member Author

I'm unable to reproduce either with the example above

@nbrustein
Copy link
Contributor

I feel like it would be helpful if there was more information in the error. We need to know what response it is that is in-progress when the error is triggered. Is there an OpenAI project where you could make a request for that?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

6 participants