OTA example crashes trying to update an ESP32S3 with secure bootloader (AEGHB-429)

Problem:

I am trying to get the OTA example working on the ESP32S3 board with secure boot loader enabled but it crashes every time after the whole binary is transferred. Sometimes during verification of the keys, sometimes after the verification. Not able to understand where the problem lies. The strange part is I have tried the same on different chips like ESP32 and ESP32C3 but there it doesn't crash.

Initiator:

The initiator example has slightly been modified to read the binary from an SD card instead of downloading it. And also the secure boot loader is enabled with the key. But no other change.

Log output from the initiator:

I (39030) esp_image: segment 0: paddr=001f0020 vaddr=3c0b0020 size=2b3b8h (177080) map I (39056) esp_image: segment 1: paddr=0021b3e0 vaddr=3fc9c800 size=04c38h ( 19512) I (39060) esp_image: segment 2: paddr=00220020 vaddr=42000020 size=a4808h (673800) map I (39153) esp_image: segment 3: paddr=002c4830 vaddr=3fca1438 size=023cch ( 9164) I (39156) esp_image: segment 4: paddr=002c6c04 vaddr=40374000 size=18778h (100216) I (39173) esp_image: segment 5: paddr=002df384 vaddr=00000000 size=00c4ch ( 3148) I (39175) esp_image: Verifying image signature... I (39177) secure_boot_v2: Take trusted digest key(s) from eFuse block(s) I (39184) secure_boot_v2: #0 app key digest == #0 trusted key digest I (39191) secure_boot_v2: Verifying with RSA-PSS... I (39252) secure_boot_v2_rsa: Signature verified successfully! W (41759) app_main: espnow wait ota num: 1 I (41759) espnow_ota_initatior: [espnow_ota_initiator_send, 394]: total_size: 987136, packet_num: 4613 I (44767) espnow_ota_initatior: count: 0, Upgrade_initiator_send, requested_num: 1, unfinished_num: 1, successed_num: 0 I (58084) espnow_ota_initatior: count: 1, Upgrade_initiator_send, requested_num: 1, unfinished_num: 1, successed_num: 0 I (58226) espnow_ota_initatior: count: 2, Upgrade_initiator_send, requested_num: 1, unfinished_num: 1, successed_num: 0 I (58334) espnow_ota_initatior: count: 3, Upgrade_initiator_send, requested_num: 1, unfinished_num: 1, successed_num: 0 I (58388) espnow_ota_initatior: count: 4, Upgrade_initiator_send, requested_num: 1, unfinished_num: 1, successed_num: 0 I (58499) espnow_ota_initatior: count: 5, Upgrade_initiator_send, requested_num: 1, unfinished_num: 1, successed_num: 0 I (58558) espnow_ota_initatior: count: 6, Upgrade_initiator_send, requested_num: 1, unfinished_num: 1, successed_num: 0 W (59062) espnow_ota_initatior: [espnow_ota_request_status, 293]: wait_ticks: 500 W (59164) espnow_ota_initatior: [espnow_ota_request_status, 293]: wait_ticks: 100 W (59265) espnow_ota_initatior: [espnow_ota_request_status, 293]: wait_ticks: 100 W (59265) espnow_ota_initatior: ESP_ERR_ESPNOW_OTA_DEVICE_NO_EXIST W (59272) app_main: [app_firmware_send, 221] espnow_ota_initiator_send I (59278) main_task: Returned from app_main()

Responder:

The responder example code has not been changed except that the secure boot loader is enabled with the signed key.

Log output from the responder

I (49723) espnow_ota_responder: The device starts to upgrade I (66477) espnow_ota_responder: Write total_size: 987136, written_size: 987136, spend time: 16s I (66478) espnow_ota_responder: Running firmware version: 1 I (66482) espnow_ota_responder: Running firmware version: 2.0.4 I (66488) esp_image: segment 0: paddr=001f0020 vaddr=3c0b0020 size=2b3b8h (177080) map I (66515) esp_image: segment 1: paddr=0021b3e0 vaddr=3fc9c800 size=04c38h ( 19512) I (66518) esp_image: segment 2: paddr=00220020 vaddr=42000020 size=a4808h (673800) map I (66591) esp_image: segment 3: paddr=002c4830 vaddr=3fca1438 size=023cch ( 9164) I (66593) esp_image: segment 4: paddr=002c6c04 vaddr=40374000 size=18778h (100216) I (66607) esp_image: segment 5: paddr=002df384 vaddr=00000000 size=00c4ch ( 3148) I (66608) esp_image: Verifying image signature... I (66611) secure_boot_v2: Take trusted digest key(s) from eFuse block(s) I (66618) secure_boot_v2: #0 app key digest == #0 trusted key digest I (66625) secure_boot_v2: Verifying with RSA-PSS... I (66685) secure_boot_v2_rsa: Signature verified successfully!

ERROR A stack overflow in task espnow_main has been detected.

Backtrace: 0x4037566e:0x3fcadb00 0x4037c2e5:0x3fcadb20 0x4037e94e:0x3fcadb40 0x4037dc50:0x3fcadbc0 0x4037ea9c:0x3fcadbe0 0x4037ea92:0xb6c89af9 |<-CORRUPTED 0x4037566e: panic_abort at /Users/nitheshparipati/esp/esp-idf/components/esp_system/panic.c:452

0x4037c2e5: esp_system_abort at /Users/nitheshparipati/esp/esp-idf/components/esp_system/port/esp_system_chip.c:84

0x4037e94e: vApplicationStackOverflowHook at /Users/nitheshparipati/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:581

0x4037dc50: vTaskSwitchContext at /Users/nitheshparipati/esp/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:3729

0x4037ea9c: _frxt_dispatch at /Users/nitheshparipati/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/portasm.S:450

0x4037ea92: _frxt_int_exit at /Users/nitheshparipati/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/portasm.S:245

ELF file SHA256: eade467ef89c0459

Rebooting... ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x3 (RTC_SW_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT) Saved PC:0x403755e1 0x403755e1: esp_restart_noos_dig at /Users/nitheshparipati/esp/esp-idf/components/esp_system/port/esp_system_chip.c:57 (discriminator 1)

SPIWP:0xee mode:DIO, clock div:1 Valid secure boot key blocks: 0 1 2 secure boot verification succeeded load:0x3fce3980,len:0x26f4 load:0x403c9700,len:0x4 load:0x403c9704,len:0xb60 load:0x403cc700,len:0x4b68 entry 0x403c989c W (66) boot: Unicore bootloader I (194) cpu_start: Unicore app I (194) cpu_start: Pro cpu up. I (194) cpu_start: Single core mode I (206) cpu_start: Pro cpu start user code I (206) cpu_start: cpu freq: 160000000 Hz I (206) cpu_start: Application information: I (209) cpu_start: Project name: otaresp I (214) cpu_start: App version: 1 I (219) cpu_start: Compile time: Oct 13 2023 02:20:02 I (225) cpu_start: ELF file SHA256: eade467ef89c0459... I (231) cpu_start: ESP-IDF: v5.1.1-dirty I (236) cpu_start: Min chip rev: v0.0 I (241) cpu_start: Max chip rev: v0.99 I (246) cpu_start: Chip rev: v0.1 I (250) heap_init: Initializing. RAM available for dynamic allocation: I (258) heap_init: At 3FC9D318 len 0004C3F8 (304 KiB): DRAM I (264) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM I (270) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM I (277) heap_init: At 600FE010 len 00001FD8 (7 KiB): RTCRAM I (284) spi_flash: detected chip: generic I (288) spi_flash: flash io: qio W (291) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header. I (305) sleep: Configure to isolate all GPIO pins in sleep state I (311) sleep: Enable automatic switching of GPIO sleep configuration I (319) app_start: Starting scheduler on CPU0 I (324) main_task: Started on CPU0 I (328) main_task: Calling app_main() I (335) pp: pp rom version: e7ae62f I (336) net80211: net80211 rom version: e7ae62f I (343) wifi:wifi driver task: 3fca5af8, prio:23, stack:6656, core=0 I (350) wifi:wifi firmware version: ce9244d I (351) wifi:wifi certification version: v7.0 I (355) wifi:config NVS flash: enabled I (359) wifi:config nano formating: disabled I (363) wifi:Init data frame dynamic rx buffer num: 32 I (368) wifi:Init management frame dynamic rx buffer num: 32 I (373) wifi:Init management short buffer num: 32 I (378) wifi:Init dynamic tx buffer num: 32 I (381) wifi:Init static tx FG buffer num: 2 I (386) wifi:Init static rx buffer size: 1600 I (390) wifi:Init static rx buffer num: 10 I (393) wifi:Init dynamic rx buffer num: 32 I (398) wifi_init: rx ba win: 6 I (401) wifi_init: tcpip mbox: 32 I (405) wifi_init: udp mbox: 6 I (409) wifi_init: tcp mbox: 6 I (413) wifi_init: tcp tx win: 5744 I (417) wifi_init: tcp rx win: 5744 I (421) wifi_init: tcp mss: 1440 I (425) wifi_init: WiFi IRAM OP enabled I (429) wifi_init: WiFi RX IRAM OP enabled I (435) phy_init: phy_version 601,98f2a71,Jun 29 2023,09:58:12 I (476) wifi:mode : sta (7c:df:a1:e8:8e:10) + softAP (7c:df:a1:e8:8e:11) I (477) wifi:enable tsf I (477) wifi:Total power save buffer number: 16 I (478) wifi:Init max length of beacon: 752/752 I (483) wifi:Init max length of beacon: 752/752 I (487) espnow: esp-now Version: 2.3.0 I (491) ESPNOW: espnow [version: 1.0] init I (495) espnow: mac: 7c:df:a1:e8:8e:10, version: 2 I (500) espnow: Enable main task I (504) espnow: main task entry W (505) app_main: Responder I (512) main_task: Returned from app_main()

Quickfix

Since the issue was Stack Overflow in the task I tried to increase the task size of espnow_main and it seems to work. But I am not satisfied with this because it works fine ESP32C3 with the original stack size.

espressif / esp-now