Memory allocation Failure after looping through ota check too many times (IDFGH-7978)

[tobyloki]

I am trying to run a variant of the pre_encrypted_ota sample from https://github.com/espressif/esp-idf/tree/release/v5.0/examples/system/ota/pre_encrypted_ota. My code basically just runs the main code infinitely so that it always checks for new ota updates. If any step fails, it restarts the loop, attempts to clean up some memory, waits 2s, and restarts. The code is shown below. However, after several loops, eventually the memory starts to run out and it gives me this error. How can I fix this?

Error log:

E (413035) Dynamic Impl: alloc(16749 bytes) failed
E (413035) esp-tls-mbedtls: read error :-0x7F00:
E (413045) TRANSPORT_BASE: esp_tls_conn_read error, errno=Success
E (413045) esp_https_ota: Connection closed, errno = 0
E (413055) esp_https_ota: Complete headers were not received

Code:

bool broken = false;
esp_decrypt_handle_t decrypt_handle = NULL;
esp_https_ota_handle_t https_ota_handle = NULL;

while (1)
{
    if (broken)
    {
        if (decrypt_handle != NULL)
        {
            esp_encrypted_img_decrypt_end(decrypt_handle);
            decrypt_handle = NULL;
        }

        if (https_ota_handle != NULL)
        {
            esp_https_ota_abort(https_ota_handle);
            https_ota_handle = NULL;
        }

        broken = false;
        vTaskDelay(2000 / portTICK_PERIOD_MS);
    }

    esp_err_t ota_finish_err = ESP_OK;
    esp_http_client_config_t config = {
        .url = "https://someurl/program_secure.bin",
        .cert_pem = server_cert_pem_start,
        .timeout_ms = 5000,
        .keep_alive_enable = true,
    };

    esp_decrypt_cfg_t cfg = {};
    cfg.rsa_pub_key = otaKey;
    cfg.rsa_pub_key_len = strlen(otaKey) + 1;
    // cfg.rsa_pub_key = rsa_private_pem_start;
    // cfg.rsa_pub_key_len = rsa_private_pem_end - rsa_private_pem_start;
    decrypt_handle = esp_encrypted_img_decrypt_start(&cfg);
    if (!decrypt_handle)
    {
        ESP_LOGE(TAG, "OTA upgrade failed");

        broken = true;
        continue;
    }

    esp_https_ota_config_t ota_config = {
        .http_config = &config,
        // .partial_http_download = true,
        // .max_http_request_size = 300000,
        .decrypt_cb = _decrypt_cb,
        .decrypt_user_ctx = (void *)decrypt_handle,
    };

    esp_err_t err = esp_https_ota_begin(&ota_config, &https_ota_handle);
    if (err != ESP_OK)
    {
        ESP_LOGE(TAG, "ESP HTTPS OTA Begin failed");

        broken = true;
        continue;
    }

    bool done = false;
    while (!done)
    {
        err = esp_https_ota_perform(https_ota_handle);
        if (err != ESP_ERR_HTTPS_OTA_IN_PROGRESS)
        {
            if (err == ESP_FAIL)
            {
                broken = true;
            }

            done = true;
            continue;
        }
        // esp_https_ota_perform returns after every read operation which gives user the ability to
        // monitor the status of OTA upgrade by calling esp_https_ota_get_image_len_read, which gives length of image
        // data read so far.
        ESP_LOGI(TAG, "Image bytes read: %d", esp_https_ota_get_image_len_read(https_ota_handle));
    }
    if (broken)
    {
        continue;
    }

    if (!esp_https_ota_is_complete_data_received(https_ota_handle))
    {
        // the OTA image was not completely received and user can customise the response to this situation.
        ESP_LOGE(TAG, "Complete data was not received.");

        broken = true;
        continue;
    }
    else
    {
        err = esp_encrypted_img_decrypt_end(decrypt_handle);
        if (err != ESP_OK)
        {
            broken = true;
            continue;
        }
        ota_finish_err = esp_https_ota_finish(https_ota_handle);
        if ((err == ESP_OK) && (ota_finish_err == ESP_OK))
        {
            ESP_LOGI(TAG, "ESP_HTTPS_OTA upgrade successful. Rebooting ...");
            vTaskDelay(1000 / portTICK_PERIOD_MS);
            esp_restart();
        }
        else
        {
            if (ota_finish_err == ESP_ERR_OTA_VALIDATE_FAILED)
            {
                ESP_LOGE(TAG, "Image validation failed, image is corrupted");
            }
            ESP_LOGE(TAG, "ESP_HTTPS_OTA upgrade failed 0x%x", ota_finish_err);

            broken = true;
            continue;
        }
    }
}

More logs:

I (351195) esp_encrypted_img: Starting Decryption Process
I (353425) esp_https_ota: Starting OTA...
I (353425) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
I (353665) esp_encrypted_img: Magic Verified
I (353665) esp_encrypted_img: Reading RSA private key
I (355895) native_ota_example: Running firmware version: 1.0.1
W (355895) native_ota_example: New firmware version 1.0.1 is older than or equal to the running firmware version 1.0.1. Will not begin ota.
E (355905) esp_https_ota: Decrypt callback failed -1
E (355915) esp_https_ota: Decryption of image header failed
E (355925) esp_encrypted_img: Invalid operation
I (357925) esp_encrypted_img: Starting Decryption Process
I (359975) esp_https_ota: Starting OTA...
I (359975) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
I (360205) esp_encrypted_img: Magic Verified
I (360215) esp_encrypted_img: Reading RSA private key
I (362445) native_ota_example: Running firmware version: 1.0.1
W (362445) native_ota_example: New firmware version 1.0.1 is older than or equal to the running firmware version 1.0.1. Will not begin ota.
E (362445) esp_https_ota: Decrypt callback failed -1
E (362465) esp_https_ota: Decryption of image header failed
E (362475) esp_encrypted_img: Invalid operation
I (364475) esp_encrypted_img: Starting Decryption Process
I (366685) esp_https_ota: Starting OTA...
I (366685) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
E (366695) Dynamic Impl: alloc(16322 bytes) failed
E (366695) esp-tls-mbedtls: read error :-0x7F00:
E (366695) TRANSPORT_BASE: esp_tls_conn_read error, errno=Success
E (366705) esp_https_ota: Connection closed, errno = 0
E (366705) esp_https_ota: Complete headers were not received
I (368725) esp_encrypted_img: Starting Decryption Process
I (370875) esp_https_ota: Starting OTA...
I (370885) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
I (371055) esp_encrypted_img: Magic Verified
I (371055) esp_encrypted_img: Reading RSA private key
I (373315) native_ota_example: Running firmware version: 1.0.1
W (373315) native_ota_example: New firmware version 1.0.1 is older than or equal to the running firmware version 1.0.1. Will not begin ota.
E (373325) esp_https_ota: Decrypt callback failed -1
E (373325) esp_https_ota: Decryption of image header failed
E (373345) esp_encrypted_img: Invalid operation
I (375345) esp_encrypted_img: Starting Decryption Process
I (377605) esp_https_ota: Starting OTA...
I (377605) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
E (377615) Dynamic Impl: alloc(16749 bytes) failed
E (377615) esp-tls-mbedtls: read error :-0x7F00:
E (377615) TRANSPORT_BASE: esp_tls_conn_read error, errno=Success
E (377635) esp_https_ota: Connection closed, errno = 0
E (377635) esp_https_ota: Complete headers were not received
I (379635) esp_encrypted_img: Starting Decryption Process
I (381585) esp_https_ota: Starting OTA...
I (381585) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
I (381815) esp_encrypted_img: Magic Verified
I (381815) esp_encrypted_img: Reading RSA private key
I (384035) native_ota_example: Running firmware version: 1.0.1
W (384035) native_ota_example: New firmware version 1.0.1 is older than or equal to the running firmware version 1.0.1. Will not begin ota.
E (384045) esp_https_ota: Decrypt callback failed -1
E (384045) esp_https_ota: Decryption of image header failed
E (384065) esp_encrypted_img: Invalid operation
I (386065) esp_encrypted_img: Starting Decryption Process
I (388875) esp_https_ota: Starting OTA...
I (388875) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
I (388885) esp_encrypted_img: Magic Verified
I (388885) esp_encrypted_img: Reading RSA private key
I (391235) native_ota_example: Running firmware version: 1.0.1
W (391235) native_ota_example: New firmware version 1.0.1 is older than or equal to the running firmware version 1.0.1. Will not begin ota.
E (391255) esp_https_ota: Decrypt callback failed -1
E (391255) esp_https_ota: Decryption of image header failed
E (391265) esp_encrypted_img: Invalid operation
I (393265) esp_encrypted_img: Starting Decryption Process
I (395815) esp_https_ota: Starting OTA...
I (395815) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
I (396045) esp_encrypted_img: Magic Verified
I (396045) esp_encrypted_img: Reading RSA private key
I (398265) native_ota_example: Running firmware version: 1.0.1
W (398265) native_ota_example: New firmware version 1.0.1 is older than or equal to the running firmware version 1.0.1. Will not begin ota.
E (398275) esp_https_ota: Decrypt callback failed -1
E (398285) esp_https_ota: Decryption of image header failed
E (398295) esp_encrypted_img: Invalid operation
I (400295) esp_encrypted_img: Starting Decryption Process
I (402465) esp_https_ota: Starting OTA...
I (402475) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
E (402475) Dynamic Impl: alloc(16322 bytes) failed
E (402475) esp-tls-mbedtls: read error :-0x7F00:
E (402485) TRANSPORT_BASE: esp_tls_conn_read error, errno=Success
E (402485) esp_https_ota: Connection closed, errno = 0
E (402495) esp_https_ota: Complete headers were not received
I (404505) esp_encrypted_img: Starting Decryption Process
I (406575) esp_https_ota: Starting OTA...
I (406575) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
I (406585) esp_encrypted_img: Magic Verified
I (406585) esp_encrypted_img: Reading RSA private key
I (408795) native_ota_example: Running firmware version: 1.0.1
W (408805) native_ota_example: New firmware version 1.0.1 is older than or equal to the running firmware version 1.0.1. Will not begin ota.
E (408805) esp_https_ota: Decrypt callback failed -1
E (408815) esp_https_ota: Decryption of image header failed
E (408825) esp_encrypted_img: Invalid operation
I (410825) esp_encrypted_img: Starting Decryption Process
I (413025) esp_https_ota: Starting OTA...
I (413025) esp_https_ota: Writing to partition subtype 17 at offset 0x1b0000
E (413035) Dynamic Impl: alloc(16749 bytes) failed
E (413035) esp-tls-mbedtls: read error :-0x7F00:
E (413045) TRANSPORT_BASE: esp_tls_conn_read error, errno=Success
E (413045) esp_https_ota: Connection closed, errno = 0
E (413055) esp_https_ota: Complete headers were not received
I (415065) esp_encrypted_img: Starting Decryption Process

[hmalpani]

Hello @tobyloki
Thanks for reporting the issue. This is being caused because memory is not freed in _decrypt_cb() function in the pre_encrypted_ota example when a failure occurs.
I am sharing a patch here. Can you try the example with it and confirm if it solves the issue?
IDFGH_7978.txt

[tobyloki]

Thanks. That seemed to fix the problem. I do have one question though. Even if err is equal to ESP_OK, is it still ok to make a call to free(pargs.data_out);?

[hmalpani]

No. When err is equal to ESP_OK, pargs.data_out is freed after writing into the partition. If we try to free it, it will give error.

[mahavirj]

@tobyloki Reopening the issue. This shall be (auto) closed when fix gets merged.