OpenAI chat completion is not working as expected since it's chunked data (IDFGH-14549) (AEGHB-968)

[ryanrdetzel]

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

General issue report

This is what I'm seeing in the logs:

D (8894) HTTP_CLIENT: content_length = -1
D (8898) OpenAI: content_length=0
D (8902) OpenAI: content_length=0
E (8905) OpenAI: ./managed_components/espressif__openai/OpenAI.c:2681 (OpenAI_Request):HTTP client fetch headers failed!
D (8917) event: no handlers have been registered for event ESP_HTTP_CLIENT_EVENT:6 posted to loop 0x3fca053c
D (8929) event: no handlers have been registered for event ESP_HTTP_CLIENT_EVENT:6 posted to loop 0x3fca053c
E (8937) OpenAI: ./managed_components/espressif__openai/OpenAI.c:1308 (OpenAI_ChatCompletionMessage):Empty result!

When I add additional debug logs in openai.c I see that the payload is correct and the response from opanai is also correct. I've narrowed down to this block but I'm not super familiar with how http and chunks work.

int content_length = esp_http_client_fetch_headers(client);
ESP_LOGD(TAG, "content_length=%d", content_length);

if (esp_http_client_is_chunked_response(client))
{
    esp_http_client_get_chunk_length(client, &content_length);
}
ESP_LOGD(TAG, "content_length=%d", content_length);
OPENAI_ERROR_CHECK_GOTO(content_length > 0, "HTTP client fetch headers failed!", end);
result = (char *)malloc(content_length + 1);

From the logs above I can tell esp_http_client_fetch_headers returns 0 here (which I think it should) because the server returns a Transfer-Encoding:chunked header. Because it's chunked the condition is met and we call esp_http_client_get_chunk_length to get the actual content_length but this also returns 0 as you can see in the second log for content_length.

Should this return an actual value from the header or is this calculated somehow?

Since this returns 0 the OPENAI_ERROR_CHECK_GOTO triggers and we don't actually process the response.

Entire example that fails

#include <string.h>
#include <stdlib.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "freertos/event_groups.h"

#include "esp_wifi.h"
#include "esp_event.h"
#include "esp_log.h"
#include "esp_system.h"
#include "nvs_flash.h"
#include "esp_netif.h"

#include "OpenAI.h"

static const char *TAG = "HTTP GET";

const char *ssid = CONFIG_WIFI_SSID;
const char *password = CONFIG_WIFI_PASSWORD;
static bool wifi_connected = false;

static void wifi_event_handler(void *event_handler_arg, esp_event_base_t event_base, int32_t event_id, void *event_data)
{
  if (event_id == WIFI_EVENT_STA_START)
  {
    printf("WIFI CONNECTING....\n");
  }
  else if (event_id == WIFI_EVENT_STA_CONNECTED)
  {
    printf("WiFi CONNECTED\n");
  }
  else if (event_id == WIFI_EVENT_STA_DISCONNECTED)
  {
    printf("WiFi lost connection\n");
    wifi_connected = false;
  }
  else if (event_id == IP_EVENT_STA_GOT_IP)
  {
    printf("Wifi got IP...\n\n");
    wifi_connected = true;
  }
}

void wifi_connection()
{
  esp_netif_init();
  esp_event_loop_create_default();
  esp_netif_create_default_wifi_sta();
  wifi_init_config_t wifi_initiation = WIFI_INIT_CONFIG_DEFAULT();
  esp_wifi_init(&wifi_initiation);

  esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, wifi_event_handler, NULL);
  esp_event_handler_register(IP_EVENT, IP_EVENT_STA_GOT_IP, wifi_event_handler, NULL);
  wifi_config_t wifi_configuration = {
      .sta = {
          .ssid = "",
          .password = ""}};
  strcpy((char *)wifi_configuration.sta.ssid, ssid);
  strcpy((char *)wifi_configuration.sta.password, password);
  esp_wifi_set_config(WIFI_IF_STA, &wifi_configuration);
  esp_wifi_start();

  esp_wifi_set_mode(WIFI_MODE_STA);
  esp_wifi_connect();
}

extern "C" void app_main(void)
{
  ESP_ERROR_CHECK(nvs_flash_init());
  ESP_ERROR_CHECK(esp_netif_init());
  ESP_ERROR_CHECK(esp_event_loop_create_default());

  wifi_connection();

  int retry_count = 0;
  const int max_retries = 10;
  while (!wifi_connected && retry_count < max_retries)
  {
    vTaskDelay(1000 / portTICK_PERIOD_MS); // Wait for 1 second
    retry_count++;
    ESP_LOGI(TAG, "Waiting for WiFi connection... (%d/%d)", retry_count, max_retries);
  }
  // If not connected, reboot

  if (true)
  {
    OpenAI_t *openai = OpenAICreate(CONFIG_OPENAI_API_KEY);

    OpenAI_ChatCompletion_t *completion = openai->chatCreate(openai);
    completion->setModel(completion, "gpt-4o"); // Set model to use
    OpenAI_StringResponse_t *response = completion->message(completion, "How big is the earth", false);

    openai->chatDelete(completion);
    OpenAIDelete(openai);
  }
}

[ryanrdetzel]

The second call to get the actual content_length calls esp_http_client_get_chunk_length which returns the chunk_length which should be set by this function but this function is never being called as I don't see this log message anywhere.

static int http_on_chunk_header(http_parser *parser)
{
    esp_http_client_handle_t client = parser->data;
    client->response->chunk_length = parser->content_length;
    ESP_LOGD(TAG, "http_on_chunk_header, chunk_length");
    return 0;
}

[ryanrdetzel]

Okay, so more reading testing. I don't think the code here for this is correct, there shouldn't be a content-length when there is chunked data so I'm not seeing how this would ever work. If I hack it like this

    if (esp_http_client_is_chunked_response(client))
    {
        esp_http_client_get_chunk_length(client, &content_length);
    }
    ESP_LOGD(TAG, "content_length=%d", content_length);
    // OPENAI_ERROR_CHECK_GOTO(content_length > 0, "HTTP client fetch headers failed!", end);
    content_length = 200000; // Guess on a size?
    result = (char *)malloc(content_length + 1);
    int read = esp_http_client_read_response(client, result, content_length);
    // if (read != content_length)
    // {
    //     ESP_LOGE(TAG, "HTTP_ERROR: read=%d, length=%d", read, content_length);
    //     free(result);
    //     result = NULL;
    // }
    // else
    // {
    result[read] = 0;
    ESP_LOGD(TAG, "result: %s, size: %d", result, strlen(result));
    // }

Everything works as expected because it can read the chunked data correctly if it gets past this initialization. So I guess the question is is this code incorrect or am I not understanding something? Ideally, esp_http_client_read_response would dynamically adjust the buffer to accommodate the chunked data since we don't know the size from the start but it doesn't appear to do that either.