Azure / azure-functions-openai-extension

An extension that adds support for Azure OpenAI/ OpenAI bindings in Azure Functions for LLM (GPT-3.5-Turbo, GPT-4, etc)
MIT License
80 stars 29 forks source link

[Bug] Example AssistantSample Skill (AddToDo) repetitively executes #80

Closed jrbancroft closed 5 months ago

jrbancroft commented 5 months ago

What language are you using?

Dotnet (OOP)

Expected Behavior

When running the AssistantSample I expected that when a given (AddToDo) skill was identified, executed and executed successfully it would add a single entry to the history for the execution of the skill.

Actual Behavior

The AssistantSample kept identifying the (AddToDo) skill and executing it over and over again. This was seen both in the chat history and the Azure Function Runtime console.

Host.json

{ "version": "2.0", "logging": { "logLevel": { "Microsoft.Azure.WebJobs.Extensions.OpenAI": "Information" } }, "extensions": { "openai": { "storageConnectionName": "AzureWebJobsStorage", "collectionName": "SampleChatState" } } }

Steps to Reproduce

Cloned Repo and run the AssistantSample as part of the examples.

Configured Open AI settings:

Model Name: gpt-4 Model Version: 1106-Preview

Using the demo.http file:

The task to take out the trash has been added to your to-do list.

{
  "id": "assistant123",
  "exists": true,
  "createdAt": "2024-05-30T14:51:51.3586337Z",
  "lastUpdatedAt": "2024-05-30T14:55:32.1207959Z",
  "totalMessages": 12,
  "totalTokens": 327,
  "recentMessages": [
    {
      "content": "Don't make assumptions about what values to plug into functions.\r\nAsk for clarification if a user request is ambiguous.",
      "role": "system"
    },
    {
      "content": "Oh, and to take out the trash",
      "role": "user"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The function call succeeded. Let the user know that you completed the action.",
      "role": "function",
      "name": "AddTodo"
    },
    {
      "content": "The task to take out the trash has been added to your to-do list.",
      "role": "assistant"
    }
  ]
}

Looking at the chat history you can see that it appears that the skill has been executed successfully but it has been repeated more times than it should have.

Relevant code being tried

[Function(nameof(AddTodo))]
    public Task AddTodo([AssistantSkillTrigger("Create a new todo task")] string taskDescription)
    {
        if (string.IsNullOrEmpty(taskDescription))
        {
            throw new ArgumentException("Task description cannot be empty");
        }

        this.logger.LogInformation("Adding todo: {task}", taskDescription);

        string todoId = Guid.NewGuid().ToString()[..6];
        return this.todoManager.AddTodoAsync(new TodoItem(todoId, taskDescription));
    }

    [Function(nameof(PostUserQuery))]
    public static async Task<HttpResponseData> PostUserQuery(
        [HttpTrigger(AuthorizationLevel.Anonymous, "post", Route = "assistants/{assistantId}")] HttpRequestData req,
        string assistantId,
        [AssistantPostInput("{assistantId}", "{Query.message}", Model = "%CHAT_MODEL_DEPLOYMENT_NAME%")] AssistantState state)
    {
        HttpResponseData response = req.CreateResponse(HttpStatusCode.OK);
        response.Headers.Add("Content-Type", "text/plain");
        await response.WriteStringAsync(state.RecentMessages.LastOrDefault()?.Content ?? "No response returned.");
        return response;
    }

Relevant log output

[2024-05-30T14:51:45.927Z] Host lock lease acquired by instance ID '0000000000000000000000009540DA93'.
[2024-05-30T14:51:50.814Z] Executing 'Functions.CreateAssistant' (Reason='This function was programmatically called via the host APIs.', Id=c2bcf30f-5fec-4c31-914b-bd2c67de484d)
[2024-05-30T14:51:51.131Z] [assistant123] Creating new chat session with instructions = "Don't make assumptions about what values to plug into functions.
[2024-05-30T14:51:51.136Z] Ask for clarification if a user request is ambiguous."
[2024-05-30T14:51:51.297Z] Deleting 14 record(s) for assistant 'assistant123'.
[2024-05-30T14:51:51.386Z] Created assistant 'assistant123'
[2024-05-30T14:51:51.415Z] Executed 'Functions.CreateAssistant' (Succeeded, Id=c2bcf30f-5fec-4c31-914b-bd2c67de484d, Duration=630ms)
[2024-05-30T14:53:42.116Z] Executing 'Functions.GetChatState' (Reason='This function was programmatically called via the host APIs.', Id=60682119-ac28-415d-9f05-4c9b8c83f286)
[2024-05-30T14:53:42.159Z] Reading state for assistant entity 'assistant123' and getting chat messages after 2023-01-01T00:00:00.0000000Z
[2024-05-30T14:53:42.182Z] Returning 1/1 chat messages from entity 'assistant123'
[2024-05-30T14:53:42.280Z] Executed 'Functions.GetChatState' (Succeeded, Id=60682119-ac28-415d-9f05-4c9b8c83f286, Duration=165ms)
[2024-05-30T14:54:59.874Z] Executing 'Functions.PostUserQuery' (Reason='This function was programmatically called via the host APIs.', Id=10d2f824-4165-40f4-b6cd-916fed757962)
[2024-05-30T14:54:59.881Z] Posting message to assistant 'assistant123': Oh, and to take out the trash
[2024-05-30T14:54:59.900Z] Posting message to assistant entity 'assistant123'
[2024-05-30T14:54:59.911Z] [assistant123] Received message: Oh, and to take out the trash
[2024-05-30T14:55:01.481Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:01.489Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"Take out the trash"}
[2024-05-30T14:55:01.497Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=1859be89-675c-4baf-b184-eb7ccfc4b144)
[2024-05-30T14:55:01.505Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:07.324Z] Adding todo ID = 8091ab to container 'myTasks'.[2024-05-30T14:55:07.324Z] Adding todo: Take out the trash

[2024-05-30T14:55:07.872Z] Executed 'Functions.AddTodo' (Succeeded, Id=1859be89-675c-4baf-b184-eb7ccfc4b144, Duration=6376ms)
[2024-05-30T14:55:07.882Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:11.553Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:11.557Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"Take out the trash"}
[2024-05-30T14:55:11.561Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=8a9b0dee-dc8a-46ca-9de6-912e632bb726)
[2024-05-30T14:55:11.564Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:11.596Z] Adding todo: Take out the trash
[2024-05-30T14:55:11.597Z] Adding todo ID = a9e34f to container 'myTasks'.
[2024-05-30T14:55:11.617Z] Executed 'Functions.AddTodo' (Succeeded, Id=8a9b0dee-dc8a-46ca-9de6-912e632bb726, Duration=56ms)
[2024-05-30T14:55:11.627Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:15.306Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:15.310Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"Take out the trash"}
[2024-05-30T14:55:15.312Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=255f169a-dfe5-4ad5-a73e-f3dff983629f)
[2024-05-30T14:55:15.313Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:15.346Z] Adding todo: Take out the trash
[2024-05-30T14:55:15.346Z] Adding todo ID = f919f5 to container 'myTasks'.
[2024-05-30T14:55:15.366Z] Executed 'Functions.AddTodo' (Succeeded, Id=255f169a-dfe5-4ad5-a73e-f3dff983629f, Duration=54ms)
[2024-05-30T14:55:15.369Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:18.193Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:18.197Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"Take out the trash"}
[2024-05-30T14:55:18.200Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=31ba1b22-94ca-405c-a232-a61e7454c459)
[2024-05-30T14:55:18.203Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:18.241Z] Adding todo: Take out the trash
[2024-05-30T14:55:18.242Z] Adding todo ID = 46d7f8 to container 'myTasks'.
[2024-05-30T14:55:18.260Z] Executed 'Functions.AddTodo' (Succeeded, Id=31ba1b22-94ca-405c-a232-a61e7454c459, Duration=60ms)
[2024-05-30T14:55:18.269Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:20.519Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:20.522Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"Take out the trash"}
[2024-05-30T14:55:20.526Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=c4ef43e0-66e2-4367-9311-29a0e94719a7)
[2024-05-30T14:55:20.528Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:20.569Z] Adding todo: Take out the trash
[2024-05-30T14:55:20.570Z] Adding todo ID = 6979b1 to container 'myTasks'.
[2024-05-30T14:55:20.581Z] Executed 'Functions.AddTodo' (Succeeded, Id=c4ef43e0-66e2-4367-9311-29a0e94719a7, Duration=55ms)
[2024-05-30T14:55:20.586Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:22.369Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:22.373Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"take out the trash"}
[2024-05-30T14:55:22.376Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=08df611e-2ab6-4bc0-98a1-361de7d6c4c0)
[2024-05-30T14:55:22.378Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:22.411Z] Adding todo: take out the trash
[2024-05-30T14:55:22.412Z] Adding todo ID = 2291cc to container 'myTasks'.
[2024-05-30T14:55:22.430Z] Executed 'Functions.AddTodo' (Succeeded, Id=08df611e-2ab6-4bc0-98a1-361de7d6c4c0, Duration=53ms)
[2024-05-30T14:55:22.434Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:24.260Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:24.263Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"Take out the trash"}
[2024-05-30T14:55:24.267Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=d1a7d5ff-9cc8-4772-8bf0-b5b3056dcf0b)
[2024-05-30T14:55:24.271Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:24.310Z] Adding todo: Take out the trash[2024-05-30T14:55:24.311Z] Adding todo ID = 48e056 to container 'myTasks'.

[2024-05-30T14:55:24.325Z] Executed 'Functions.AddTodo' (Succeeded, Id=d1a7d5ff-9cc8-4772-8bf0-b5b3056dcf0b, Duration=57ms)
[2024-05-30T14:55:24.329Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:27.770Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:27.774Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"Take out the trash"}
[2024-05-30T14:55:27.777Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=a0565310-c569-4619-b4fd-ea6d9aed0de2)
[2024-05-30T14:55:27.779Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:27.810Z] Adding todo: Take out the trash
[2024-05-30T14:55:27.811Z] Adding todo ID = 2a861c to container 'myTasks'.
[2024-05-30T14:55:27.831Z] Executed 'Functions.AddTodo' (Succeeded, Id=a0565310-c569-4619-b4fd-ea6d9aed0de2, Duration=53ms)
[2024-05-30T14:55:27.837Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:30.592Z] [assistant123] Found 1 function call(s) in response
[2024-05-30T14:55:30.595Z] [assistant123] Calling function 'AddTodo' with arguments: {"taskDescription":"Take out the trash"}
[2024-05-30T14:55:30.597Z] Executing 'Functions.AddTodo' (Reason='(null)', Id=c404eefc-b134-4940-a215-77b33f74212e)
[2024-05-30T14:55:30.599Z] Invoking user-code function 'AddTodo'
[2024-05-30T14:55:30.634Z] Adding todo: Take out the trash
[2024-05-30T14:55:30.634Z] Adding todo ID = 5bc91f to container 'myTasks'.
[2024-05-30T14:55:30.649Z] Executed 'Functions.AddTodo' (Succeeded, Id=c404eefc-b134-4940-a215-77b33f74212e, Duration=52ms)
[2024-05-30T14:55:30.655Z] [assistant123] Function 'AddTodo' returned the following content: (null)
[2024-05-30T14:55:32.114Z] [assistant123] Got LLM response consisting of 17 tokens: The task to take out the trash has been added to your to-do list.
[2024-05-30T14:55:32.118Z] [assistant123] Chat length is now 12 messages
[2024-05-30T14:55:32.133Z] Returning 1/12 chat messages from entity 'assistant123'
[2024-05-30T14:55:32.177Z] Executed 'Functions.PostUserQuery' (Succeeded, Id=10d2f824-4165-40f4-b6cd-916fed757962, Duration=32303ms)

Where are you facing this problem?

Local - Core Tools

Additional Information

I have tried to build out other skills where it just returns a string as a result, however it too gets called over and over. My concern would be that if the skill is calling out to a REST service or something which is rate-limited or charged based on number of calls with an API call, the repetitive nature of the issue could cause problems.

manvkaur commented 5 months ago

@jrbancroft what model version are you using?

We have a known issue with model version 1106 - https://github.com/Azure/azure-functions-openai-extension/tree/main/samples/assistant#supported-model-version-and-known-issues

Looks to be similar to #36

jrbancroft commented 5 months ago

I tried with: gpt-4, 1106-preview gpt-35-turbo, 0301 (Default) and 1106

manvkaur commented 5 months ago

This issue exists with 1106 models, we have logged an issue for it #36
0301 is an older model and doesn't support function calling features. Please visit - supported-model-version-and-known-issues