esp_ota_write is 30 x SLOWER after update to ESP-IDF 5.4.2

[jcolebaker]

We are migrating an older product from ESP-IDF v4.4.4 to v5.4.2

We have an OTA update process which uses BLE to receive update files. The data is received and written to flash in 8 KiB chunks, using the esp_ota_write function. We are using secure boot (v2) and flash encryption, and the encryption is enabled for the OTA download partitions.

We have found that the OTA download is much slower after porting the code to v5.4.2, because esp_ota_write is now very slow.

Previous time to write 8192 bytes (ESP-IDF v4.4.4): 90 mS
New time to write 8192 bytes (ESP-IDF v5.4.2): 2,850 mS (31 x longer!)

I have not changed the partition table, OTA code or SDK config as part of the port to the new SDK version, except where some changes were needed due to API changes. I don't think anything I changed was relevant to ESP OTA functions.

Any idea why the flash write operation got so much slower? Is there a new "Make the flash write fast" option I haven't turned on?

P.S. - CONFIG_SPI_FLASH_VERIFY_WRITE Option: I have just turned OFF the "Verify SPI flash writes" option ("CONFIG_SPI_FLASH_VERIFY_WRITE"). This made the write operation MUCH faster; now each block takes around 50 mS (faster than before the SDK update!). However, "Verify SPI flash writes" was definitely ON in our configuration with the old SDK and 8 KiB writes were still quite fast (90 mS).
* Why is the verify option so much slower now?
* Is it a useful option, or should I just turn it off?

Partition Table:

Code: Select all

# ESP-IDF Partition Table
# Name,Type,SubType,Offset,Size,Flags
nvs,data,nvs,0xF000,28K,
otadata,data,ota,0x16000,8K,
phy_init,data,phy,0x18000,4K,
nvs_factory,data,nvs,0x19000,32K,
nvs_user,data,nvs,0x21000,64K,
nvs_keys,data,nvs_keys,0x31000,4K,encrypted
certificates,data,fat,0x32000,120K,encrypted
coredump,data,coredump,0x50000,64K,encrypted
logs,data,fat,0x60000,1024K,
history_data,data,fat,0x160000,128K,
factory,app,factory,0x180000,2048K,encrypted
ota_0,app,ota_0,0x380000,2304K,encrypted
ota_1,app,ota_1,0x5C0000,2304K,encrypted

OTA Code:

Code: Select all

static esp_ota_handle_t l_update_handle = NO_OTA_HANDLE;

// At start of OTA:
l_update_partition = esp_ota_get_next_update_partition(NULL);
//...
esp_err_t esp_result = esp_ota_begin(l_update_partition, OTA_SIZE_UNKNOWN, &l_update_handle);


// When 8192 byte page received from BLE:
OtaResultT WcOtaWritePageSequential(const uint8_t *p_page_data, size_t page_size)
{
    OtaResultT result = otrSUCCESS;

    ESP_LOGI(TAG, "Write firmware page: %zu bytes...", page_size);

    OtaWatchdogHandleT watchdog_handle = OtaWatchdogStart("Flash Write", FLASH_PAGE_WRITE_WATCHDOG_TIMEOUT_MS);

    esp_err_t write_result = esp_ota_write(l_update_handle, (const void *)p_page_data, page_size);
    if (result != ESP_OK)
    {
        ESP_LOGE(TAG, "ERROR: esp_ota_write failed (%d)", write_result);
        result = otrPAGE_WRITE_FAILED;
    }
    else
    {
        ESP_LOGI(TAG, COLOUR_BLUE "Firmware page write finished.");
    }

    OtaWatchdogCancel(watchdog_handle);
    return result;
}

SPI Flash Driver Config Options:

Code: Select all

(Top) → Component config → SPI Flash driver
Espressif IoT Development Framework Configuration
[*] Verify SPI flash writes
[*]     Log errors if verification fails
[*]     Log warning if writing zero bits to ones
[ ] Enable operation counters
[*] Enable SPI flash ROM driver patched functions
Writing to dangerous flash regions (Aborts)  --->
[ ] Support other devices attached to SPI1 bus
[ ] Bypass a block erase and always do sector erase
[*] Enables yield operation during flash erase
(20)    Duration of erasing to yield CPUs (ms)
(1)     CPU release time (tick) for an erase operation
(8192) Flash write chunk size
[ ] Override flash size in bootloader header by ESPTOOLPY_FLASHSIZE
[ ] Flash timeout checkout disabled
[ ] Override default chip driver list
Auto-detect flash chips  --->
-*- Enable encrypted partition read/write operations

Output Logs:

Code: Select all

# With ESP-IDF 4.4.4 (old):
I (156111) OTAM: OTA firmware page received: 8192 bytes this page, 106496 bytes total
I (156121)  OTA: Write firmware page: 8192 bytes...
I (156121) OTWD: OTA watchdog 'Flash Write' timeout in 4000 ms
I (156211)  OTA: Firmware page write finished.

# Approximate write time: 156211 - 156121 =  90 mS


# With ESP-IDF 5.4.2 (new):
I (403730) OTAM: OTA firmware page received: 8192 bytes this page, 712704 bytes total
I (403740)  OTA: Write firmware page: 8192 bytes...
I (403740) OTWD: OTA watchdog 'Flash Write' timeout in 4000 ms
I (406590)  OTA: Firmware page write finished.

# Approximate write time: 406590 - 403740 = 2,850 mS (!!!)