OTA doesn't work with encryption enabled (AEGHB-260)

[n3b0j5a]

I have two boards, one based on ESP32-S3 as an initiator and another one based on ESP32-C3 as responder and I'm trying to use S3 board to download update for C3 and push it. I customized OTA download process a bit to achieve 2 things:

• Disable firmware verification to prevent failure due to chip variant difference
• Download firmware to an nvs partition instead of ota_x. I want to preserve initiator ota partitions for eventual rollback.

Both chips are development encrypted. However, when trying to transfer firmware to C3 device, i get the error code:

I (38024) espnow_ota_responder: write packet size: 214
E (38024) spi_flash: flash encrypted write length must be multiple of 16
W (38034) espnow_ota_responder: [espnow_ota_write, 283] <ERROR> esp_partition_write ESP_ERR_INVALID_SIZE
W (38044) espnow_ota_responder: [espnow_ota_responder_data_process, 432] <ERROR> espnow_ota_handle
I (38054) espnow_ota_responder: write packet size: 214
E (38054) spi_flash: flash encrypted write address must be 16 bytes aligned
W (38064) espnow_ota_responder: [espnow_ota_write, 283] <ERROR> esp_partition_write ESP_ERR_INVALID_ARG
W (38074) espnow_ota_responder: [espnow_ota_responder_data_process, 432] <ERROR> espnow_ota_handle
I (38084) espnow_ota_responder: write packet size: 214
E (38094) spi_flash: flash encrypted write address must be 16 bytes aligned
W (38094) espnow_ota_responder: [espnow_ota_write, 283] <ERROR> esp_partition_write ESP_ERR_INVALID_ARG
W (38104) espnow_ota_responder: [espnow_ota_responder_data_process, 432] <ERROR> espnow_ota_handle
I (38114) espnow_ota_responder: write packet size: 214
E (38124) spi_flash: flash encrypted write address must be 16 bytes aligned
W (38134) espnow_ota_responder: [espnow_ota_write, 283] <ERROR> esp_partition_write ESP_ERR_INVALID_ARG
W (38144) espnow_ota_responder: [espnow_ota_responder_data_process, 432] <ERROR> espnow_ota_handle

I suspect that this is due to the fact that flash must be written in 16 bytes blocks when encryption is enabled.

Demo code listing for initiator:

#include "sys/param.h"

#include "esp_log.h"
#include "esp_system.h"
#include "freertos/FreeRTOS.h"
#include "freertos/timers.h"
#include "esp_wifi.h"
#include "nvs_flash.h"
#include "esp_mac.h"
#include "esp_flash_encrypt.h"
#include "esp_app_format.h"
#include "esp_image_format.h"
#include "esp_http_client.h"
#include "esp_ota_ops.h"
#include "espnow_utils.h"
#include "espnow.h"
#include "espnow_ota.h"
#include "espnow_ctrl.h"
#include "spi_flash_mmap.h"

#define UNBIND_TOTAL_COUNT               (5)

static const char *TAG = "APP";

static led_strip_handle_t g_strip_handle = NULL;

/* Partial_data is word aligned so no reallocation is necessary for encrypted flash write */
typedef struct {
    const esp_partition_t *part;
    bool need_erase;
    uint32_t wrote_size;
    uint8_t partial_bytes;
    WORD_ALIGNED_ATTR uint8_t partial_data[16];
} ota_ops_entry_t;

esp_err_t app_ota_begin(const esp_partition_t *partition, size_t image_size, ota_ops_entry_t *out_entry)
{
    esp_err_t ret = ESP_OK;

    if (partition == NULL) {
        return ESP_ERR_INVALID_ARG;
    }

    partition = esp_partition_verify(partition);
    if (partition == NULL) {
        return ESP_ERR_NOT_FOUND;
    }

    if (image_size != OTA_WITH_SEQUENTIAL_WRITES) {
        // If input image size is 0 or OTA_SIZE_UNKNOWN, erase entire partition
        if ((image_size == 0) || (image_size == OTA_SIZE_UNKNOWN)) {
            ret = esp_partition_erase_range(partition, 0, partition->size);
        } else {
            const int aligned_erase_size = (image_size + SPI_FLASH_SEC_SIZE - 1) & ~(SPI_FLASH_SEC_SIZE - 1);
            ret = esp_partition_erase_range(partition, 0, aligned_erase_size);
        }
        if (ret != ESP_OK) {
            return ret;
        }
    }

    out_entry->part = partition;
    out_entry->need_erase = (image_size == OTA_WITH_SEQUENTIAL_WRITES);
    return ESP_OK;
}

esp_err_t app_ota_write(ota_ops_entry_t *entry, const void *data, size_t size)
{
    const uint8_t *data_bytes = (const uint8_t *)data;
    esp_err_t ret;

    if (data == NULL) {
        ESP_LOGE(TAG, "write data is invalid");
        return ESP_ERR_INVALID_ARG;
    }

    // find ota handle in linked list
    if (entry->need_erase) {
        // must erase the partition before writing to it
        uint32_t first_sector = entry->wrote_size / SPI_FLASH_SEC_SIZE;
        uint32_t last_sector = (entry->wrote_size + size) / SPI_FLASH_SEC_SIZE;

        ret = ESP_OK;
        if ((entry->wrote_size % SPI_FLASH_SEC_SIZE) == 0) {
            ret = esp_partition_erase_range(entry->part, entry->wrote_size, ((last_sector - first_sector) + 1) * SPI_FLASH_SEC_SIZE);
        } else if (first_sector != last_sector) {
            ret = esp_partition_erase_range(entry->part, (first_sector + 1) * SPI_FLASH_SEC_SIZE, (last_sector - first_sector) * SPI_FLASH_SEC_SIZE);
        }
        if (ret != ESP_OK) {
            return ret;
        }
    }

    if (entry->wrote_size == 0 && entry->partial_bytes == 0 && size > 0 && data_bytes[0] != ESP_IMAGE_HEADER_MAGIC) {
        ESP_LOGE(TAG, "OTA image has invalid magic byte (expected 0xE9, saw 0x%02x)", data_bytes[0]);
        return ESP_ERR_OTA_VALIDATE_FAILED;
    }

    if (esp_flash_encryption_enabled()) {
        /* Can only write 16 byte blocks to flash, so need to cache anything else */
        size_t copy_len;

        /* check if we have partially written data from earlier */
        if (entry->partial_bytes != 0) {
            copy_len = MIN(16 - entry->partial_bytes, size);
            memcpy(entry->partial_data + entry->partial_bytes, data_bytes, copy_len);
            entry->partial_bytes += copy_len;
            if (entry->partial_bytes != 16) {
                return ESP_OK; /* nothing to write yet, just filling buffer */
            }
            /* write 16 byte to partition */
            ret = esp_partition_write(entry->part, entry->wrote_size, entry->partial_data, 16);
            if (ret != ESP_OK) {
                return ret;
            }
            entry->partial_bytes = 0;
            memset(entry->partial_data, 0xFF, 16);
            entry->wrote_size += 16;
            data_bytes += copy_len;
            size -= copy_len;
        }

        /* check if we need to save trailing data that we're about to write */
        entry->partial_bytes = size % 16;
        if (entry->partial_bytes != 0) {
            size -= entry->partial_bytes;
            memcpy(entry->partial_data, data_bytes + size, entry->partial_bytes);
        }
    }

    ret = esp_partition_write(entry->part, entry->wrote_size, data_bytes, size);
    if(ret == ESP_OK){
        entry->wrote_size += size;
    }
    return ret;
}

esp_err_t app_ota_end(ota_ops_entry_t *entry)
{
    esp_err_t ret = ESP_OK;

    if (entry == NULL) {
        return ESP_ERR_NOT_FOUND;
    }

    /* 'it' holds the ota_ops_entry_t for 'handle' */

    // esp_ota_end() is only valid if some data was written to this handle
    if (entry->wrote_size == 0) {
        return ESP_ERR_INVALID_ARG;
    }

    if (entry->partial_bytes > 0) {
        /* Write out last 16 bytes, if necessary */
        ret = esp_partition_write(entry->part, entry->wrote_size, entry->partial_data, 16);
        if (ret != ESP_OK) {
            return ESP_ERR_INVALID_STATE;
        }
        entry->wrote_size += 16;
        entry->partial_bytes = 0;
    }

    return ESP_OK;
}

static size_t app_firmware_download(const esp_partition_t *partition, const char *url)
{

#define OTA_DATA_PAYLOAD_LEN 1024

    esp_err_t ret       = ESP_OK;

    ota_ops_entry_t *entry = (ota_ops_entry_t *) ESP_CALLOC(sizeof(ota_ops_entry_t), 1);

    uint8_t *data       = ESP_MALLOC(OTA_DATA_PAYLOAD_LEN);
    size_t total_size   = 0;
    uint32_t start_time = xTaskGetTickCount();

    esp_http_client_config_t config = {
        .url            = url,
        .transport_type = HTTP_TRANSPORT_UNKNOWN,
    };

    esp_http_client_handle_t client = esp_http_client_init(&config);
    ESP_ERROR_GOTO(!client, EXIT, "Initialise HTTP connection");
    ESP_LOGI(TAG, "Open HTTP connection: %s", url);

    do {
        ret = esp_http_client_open(client, 0);

        if (ret != ESP_OK) {
            vTaskDelay(pdMS_TO_TICKS(1000));
            ESP_LOGW(TAG, "<%s> Connection service failed", esp_err_to_name(ret));
        }
    } while (ret != ESP_OK);

    total_size = esp_http_client_fetch_headers(client);

    if (total_size <= 0) {
        ESP_LOGW(TAG, "Please check the address of the server");
        ret = esp_http_client_read(client, (char *)data, OTA_DATA_PAYLOAD_LEN);
        ESP_ERROR_GOTO(ret < 0, EXIT, "<%s> Read data from http stream", esp_err_to_name(ret));

        ESP_LOGW(TAG, "Recv data: %.*s", ret, data);
        goto EXIT;
    }

    /**
     * @brief 2. Read firmware from the server and write it to the flash of the root node
     */

    /**< Commence an OTA update writing to the specified partition. */
    ESP_LOGI(TAG, "total_size: %d", total_size);

    ret = app_ota_begin(partition, total_size, entry);
    ESP_ERROR_GOTO(ret != ESP_OK, EXIT, "<%s> esp_ota_begin failed, total_size", esp_err_to_name(ret));

    for (ssize_t size = 0, recv_size = 0; recv_size < total_size; recv_size += size) {
        size = esp_http_client_read(client, (char *)data, OTA_DATA_PAYLOAD_LEN);
        ESP_ERROR_GOTO(size < 0, EXIT, "<%s> Read data from http stream", esp_err_to_name(ret));

        if (size > 0) {
            /**< Write OTA update data to partition */
            ret = app_ota_write(entry, data, OTA_DATA_PAYLOAD_LEN);
            ESP_ERROR_GOTO(ret != ESP_OK, EXIT, "<%s> Write firmware to flash, size: %u, data: %.*s",
                           esp_err_to_name(ret), size, size, data);
        } else {
            ESP_LOGW(TAG, "<%s> esp_http_client_read", esp_err_to_name(ret));
            goto EXIT;
        }
    }

    ESP_LOGI(TAG, "The service download firmware is complete, Spend time: %" PRIu32 "s",
             (xTaskGetTickCount() - start_time) * portTICK_PERIOD_MS / 1000);

    ret = app_ota_end(entry);
    ESP_ERROR_GOTO(ret != ESP_OK, EXIT, "<%s> esp_ota_end", esp_err_to_name(ret));

EXIT:
    ESP_FREE(data);
    ESP_FREE(entry);
    esp_http_client_close(client);
    esp_http_client_cleanup(client);

    return total_size;
}

esp_err_t app_ota_initiator_data_cb(size_t src_offset, void *dst, size_t size)
{
    const esp_partition_t *data_partition = esp_partition_find_first(ESP_PARTITION_TYPE_DATA, ESP_PARTITION_SUBTYPE_DATA_NVS, "nvs_ota");
    if (data_partition == NULL) {
        return ESP_ERR_INVALID_ARG;
    }

    return esp_partition_read(data_partition, src_offset, dst, size);
}

static void app_firmware_send(size_t firmware_size, uint8_t sha[ESPNOW_OTA_HASH_LEN])
{
    esp_err_t ret       = ESP_OK;
    uint32_t start_time = xTaskGetTickCount();
    espnow_ota_result_t espnow_ota_result = {0};
    espnow_ota_responder_t *info_list = NULL;
    espnow_addr_t *dest_addr_list = NULL;
    size_t num = 0;

    espnow_ota_initiator_scan(&info_list, &num, pdMS_TO_TICKS(3000));
    ESP_LOGW(TAG, "espnow wait ota num: %u", num);

    if (!num) {
        goto EXIT;
    }

    dest_addr_list = ESP_MALLOC(num * ESPNOW_ADDR_LEN);

    for (size_t i = 0; i < num; i++) {
        memcpy(dest_addr_list[i], info_list[i].mac, ESPNOW_ADDR_LEN);
    }

    espnow_ota_initiator_scan_result_free();

    ret = espnow_ota_initiator_send(dest_addr_list, num, sha, firmware_size, app_ota_initiator_data_cb, &espnow_ota_result);
    ESP_ERROR_GOTO(ret != ESP_OK, EXIT, "<%s> espnow_ota_initiator_send", esp_err_to_name(ret));

    if (espnow_ota_result.successed_num == 0) {
        ESP_LOGW(TAG, "Devices upgrade failed, unfinished_num: %u", espnow_ota_result.unfinished_num);
        goto EXIT;
    }

    ESP_LOGI(TAG, "Firmware is sent to the device to complete, Spend time: %" PRIu32 "s",
             (xTaskGetTickCount() - start_time) * portTICK_PERIOD_MS / 1000);
    ESP_LOGI(TAG, "Devices upgrade completed, successed_num: %u, unfinished_num: %u",
             espnow_ota_result.successed_num, espnow_ota_result.unfinished_num);

EXIT:
    ESP_FREE(dest_addr_list);
    espnow_ota_initiator_result_free(&espnow_ota_result);
}

static void wifi_event_handler(void* arg, esp_event_base_t event_base,int32_t event_id, void* event_data)
{

    if (event_base == WIFI_EVENT) {
        switch(event_id) {
            case WIFI_EVENT_STA_START:
            esp_wifi_connect();
            break;
            case WIFI_EVENT_STA_CONNECTED:
            break;
        }
    }
}

static void app_wifi_init()
{
    ESP_ERROR_CHECK(esp_netif_init());
    esp_event_loop_create_default();
    esp_netif_create_default_wifi_sta();

    wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT();
    ESP_ERROR_CHECK(esp_wifi_init(&cfg));
    ESP_ERROR_CHECK(esp_wifi_set_storage(WIFI_STORAGE_RAM));
    ESP_ERROR_CHECK(esp_wifi_set_ps(WIFI_PS_NONE));

    ESP_ERROR_CHECK(esp_event_handler_instance_register(WIFI_EVENT,ESP_EVENT_ANY_ID, &wifi_event_handler, NULL, NULL)); 

    wifi_config_t wifi_config = {
        .sta = {
            .ssid = "myssid",
            .password = "mypassword",
            .sae_pwe_h2e = WPA3_SAE_PWE_BOTH,
        },
    };

    ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_STA));
    ESP_ERROR_CHECK(esp_wifi_set_config(WIFI_IF_STA, &wifi_config));
    ESP_ERROR_CHECK(esp_wifi_start());
}

static void app_espnow_event_handler(void *handler_args, esp_event_base_t base, int32_t id, void *event_data)
{
    if (base != ESP_EVENT_ESPNOW) {
        return;
    }

    switch (id) {
        case ESP_EVENT_ESPNOW_CTRL_BIND: {
            espnow_ctrl_bind_info_t *info = (espnow_ctrl_bind_info_t *)event_data;
            ESP_LOGI(TAG, "bind, uuid: " MACSTR ", initiator_type: %d", MAC2STR(info->mac), info->initiator_attribute);
            espnow_ctrl_responder_set_bindlist(info);
            break;
        }

        case ESP_EVENT_ESPNOW_CTRL_UNBIND: {
            espnow_ctrl_bind_info_t *info = (espnow_ctrl_bind_info_t *)event_data;
            ESP_LOGI(TAG, "unbind, uuid: " MACSTR ", initiator_type: %d", MAC2STR(info->mac), info->initiator_attribute);
            espnow_ctrl_responder_remove_bindlist(info);
            break;
        }

        default:
            break;
    }
}

static esp_err_t unbind_restore_init(void)
{
    if (espnow_reboot_unbroken_count() >= UNBIND_TOTAL_COUNT) {
        ESP_LOGI(TAG, "unbind restore");
        espnow_storage_erase("bindlist");
        app_led_set_color(255, 0, 0);
        return espnow_reboot(CONFIG_ESPNOW_REBOOT_UNBROKEN_INTERVAL_TIMEOUT);
    }

    return ESP_OK;
}

static void app_espnow_event_handler(void *handler_args, esp_event_base_t base, int32_t id, void *event_data)
{
    if (base != ESP_EVENT_ESPNOW) {
        return;
    }

    switch (id) {
        case ESP_EVENT_ESPNOW_CTRL_BIND: {
            espnow_ctrl_bind_info_t *info = (espnow_ctrl_bind_info_t *)event_data;
            ESP_LOGI(TAG, "bind, uuid: " MACSTR ", initiator_type: %d", MAC2STR(info->mac), info->initiator_attribute);
            espnow_ctrl_responder_set_bindlist(info);
            break;
        }

        case ESP_EVENT_ESPNOW_CTRL_UNBIND: {
            espnow_ctrl_bind_info_t *info = (espnow_ctrl_bind_info_t *)event_data;
            ESP_LOGI(TAG, "unbind, uuid: " MACSTR ", initiator_type: %d", MAC2STR(info->mac), info->initiator_attribute);
            espnow_ctrl_responder_remove_bindlist(info);
            break;
        }

        default:
            break;
    }
}

void app_flash_init(void)
{
    esp_err_t err = nvs_flash_init();
    if (err == ESP_ERR_NVS_NO_FREE_PAGES || err == ESP_ERR_NVS_NEW_VERSION_FOUND) {
        ESP_ERROR_CHECK(nvs_flash_erase());
        err = nvs_flash_init();
    }

    esp_partition_t *user_keys_partition = (esp_partition_t *)esp_partition_find_first(ESP_PARTITION_TYPE_DATA, ESP_PARTITION_SUBTYPE_DATA_NVS_KEYS, "nvs_secret");
    assert(user_keys_partition != NULL);

    nvs_sec_cfg_t cfg;
    err = nvs_flash_read_security_cfg(user_keys_partition, &cfg); 
    if (err == ESP_ERR_NVS_KEYS_NOT_INITIALIZED || ESP_ERR_NVS_CORRUPT_KEY_PART == err)
    {
        err = nvs_flash_generate_keys(user_keys_partition, &cfg);
    }
    ESP_ERROR_CHECK(err);
}

void app_main(void)
{
    app_flash_init();
    espnow_storage_init();
    app_led_init();

    unbind_restore_init();

    app_wifi_init();

    espnow_config_t espnow_config = ESPNOW_INIT_CONFIG_DEFAULT();
    espnow_init(&espnow_config);

    esp_event_handler_register(ESP_EVENT_ESPNOW, ESP_EVENT_ANY_ID, app_espnow_event_handler, NULL);

     vTaskDelay(pdMS_TO_TICKS(5000));
    const esp_partition_t *data_partition = esp_partition_find_first(ESP_PARTITION_TYPE_DATA, ESP_PARTITION_SUBTYPE_DATA_NVS, "nvs_ota");
    size_t firmware_size = app_firmware_download(data_partition, "http://10.6.6.7/switch.bin");
    uint8_t sha_256[32] = {0};
    esp_partition_get_sha256(data_partition, sha_256);

    app_firmware_send(firmware_size, sha_256);
}

[n3b0j5a]

This solves SPI flash error.

#define ESPNOW_OTA_PACKET_MAX_SIZE             ((ESPNOW_DATA_LEN - 4) - (ESPNOW_DATA_LEN -4) % 16)  /**< Maximum length of a single packet transmitted */

However, process stops after last chunk is received. Still investigating....

[lhespress]

@n3b0j5a You're right, flash must be written in 16 bytes blocks when encryption is enabled. What's the length of the last chunk data?

[n3b0j5a]

@lhespress Encrypted firmware is padded anyway, that should not be a problem. I made patch fix that resolve this issue: https://github.com/espressif/esp-now/pull/80

[n3b0j5a]

Can someone take a look at pull requests? I really need that fixes merged.

[lhespress]

@n3b0j5a Thanks for your contribution, the #80 has been merged.

[n3b0j5a]

Thanks!