Infinite reset in the boot-loader of esp-idf v3.0 with a small size application

[valentin]

Dear Espressif Support,

When testing a small application, the board (ESP32 WROVER kit v3) reset infinitely inside the boot-loader. See in the attached file the exception that occurs.

It is not a power surge issue, as this kind of exception usually is, as the board is supplied by external 5V supply that can provide up to 2A.

This is most likely a race condition in the boot-loader regarding memory initialization, which depends of the application size the boot-loader needs to load:
- if some logs are enabled in the application, the issue is gone => since the application is not even reached when the exception occurs, just by increasing the size of the application the issue is gone
- if a log is added in function start_cpu0_default, to delay slightly the CPU0 user startup code, the issue is also gone

I noticed among other applications that the issue occurs only if I see 6 segments loaded by the bootloader (esp_image: ... sequence). If I have 7 segments or more, the issue is gone.

Could you confirm that this issue exists in esp-idf release v3.0? Do you have a fix for this issue in later releases, or even master branch?

Thank you,
Valentin

[ESP_igrr]

Could you please use idf_monitor to decode the backtrace as explained in https://docs.espressif.com/projects/esp ... -backtrace?

[valentin]

See below trace obtained with make monitor:

Code: Select all

Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x3e (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:5648
ho 0 tail 12 room 4
load:0x40078000,len:0
load:0x40078000,len:12180
entry 0x40078f94
I (30) boot: ESP-IDF v3.0 2nd stage bootloader
I (30) boot: compile time 12:28:26
I (46) boot: Enabling RNG early entropy source...
I (46) boot: SPI Speed      : 40MHz
I (46) boot: SPI Mode       : DIO
I (48) boot: SPI Flash Size : 4MB
I (52) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (71) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 001b0000
I (86) boot: End of partition table
I (90) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1fff0 (131056) map
I (145) esp_image: segment 1: paddr=0x00030018 vaddr=0x400d0018 size=0x31dc4 (204228) map
0x400d0018: _flash_cache_start at ??:?

I (216) esp_image: segment 2: paddr=0x00061de4 vaddr=0x3ffc0000 size=0x0219c (  8604) load
I (220) esp_image: segment 3: paddr=0x00063f88 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at C:/Gits/ESP32-WROVER/P0065_ESP32-WROVER-Platform/ESP32-WROVER-Xtensa-FreeRTOS-bsp/Drivers/esp-idf/components/freertos/xtensa_vectors.S:1685

I (223) esp_image: segment 4: paddr=0x00064390 vaddr=0x40080400 size=0x0c568 ( 50536) load
I (252) esp_image: segment 5: paddr=0x00070900 vaddr=0x400c0000 size=0x00000 (     0) load
I (260) boot: Loaded app from partition at offset 0x10000
I (260) boot: Disabling RNG early entropy source...
I (262) spiram: SPI RAM mode: flash 40m sram 40m
I (267) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (274) cpu_start: Pro cpu up.
I (278) cpu_start: Starting app cpu, entry point is 0x400811c4
0x400811c4: call_start_cpu1 at C:/Gits/ESP32-WROVER/P0065_ESP32-WROVER-Platform/ESP32-WROVER-Xtensa-FreeRTOS-bsp/Drivers/esp-idf/components/esp32/cpu_start.c:219

I (269) cpu_start: App cpu up.
I (1139) spiram: SPI SRAM memory test OK
I (1140) heap_init: Initializing. RAM available for dynamic allocation:
I (1140) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1146) heap_init: At 3FFC7850 len 000187B0 (97 KiB): DRAM
I (1152) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (1159) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1165) heap_init: At 4008C968 len 00013698 (77 KiB): IRAM
I (1171) cpu_start: Pro cpu start user code
Guru Meditation Error: Core  0 panic'ed (InstrFetchProhibited)
. Exception was unhandled.
Register dump:
PC      : 0xffffffff  PS      : 0x00060b30  A0      : 0x800813ce  A1      : 0x3ffe3c20
A2      : 0x3f420008  A3      : 0x3f420008  A4      : 0xffffffff  A5      : 0x3ffc2724
A6      : 0x00000000  A7      : 0xfffffff6  A8      : 0x8008111b  A9      : 0x3ffe3c00
A10     : 0x00000000  A11     : 0x004c75e7  A12     : 0x3ffc21fc  A13     : 0x3ffc2200
A14     : 0x00000000  A15     : 0x00000002  SAR     : 0x0000001d  EXCCAUSE: 0x00000014
EXCVADDR: 0xfffffffc  LBEG    : 0x4008bfdc  LEND    : 0x4008bfe7  LCOUNT  : 0xffffffff
0x4008bfdc: memset at /home/jeroen/esp8266/esp32/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/machine/xtensa/../../../../.././newlib/libc/machine/xtensa/memset.S:142

0x4008bfe7: memset at /home/jeroen/esp8266/esp32/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/machine/xtensa/../../../../.././newlib/libc/machine/xtensa/memset.S:152


Backtrace: 0x7fffffff:0x3ffe3c20 0x400813cb:0x3ffe3c50 0x40078f58:0x3ffe3c70 0x400790a2:0x3ffe3e70 0x40007c31:0x3ffe3eb0 0x4000073d:0x3ffe3f20
0x400813cb: call_start_cpu0 at C:/Gits/ESP32-WROVER/P0065_ESP32-WROVER-Platform/ESP32-WROVER-Xtensa-FreeRTOS-bsp/Drivers/esp-idf/components/esp32/cpu_start.c:207

I fix this with a workaround, I added a first line in start_cpu0_default() function to print something:

Code: Select all

ESP_EARLY_LOGI(TAG, "Starting pro cpu user code.");

[ESP_igrr]

The backtrace indicates that the PRO CPU has been reset somewhere after the "cpu_start: Pro cpu start user code" message, and then crashed in startup code (two functions at the bottom of the stack are _entry and main). However the exception was handled by IDF panic handler, which means that the exception vector base address was not reset back to its ROM location... which is quite hard to explain. If you have a binary which reproduces this crash, could you upload it somewhere (or send it via a PM)? We can try it locally to verify that this isn't a hardware issue and then debug this over JTAG? Thanks.

[valentin]

Hi ESP_igrr,

I've sent you a private message with the binaries.
Hope it helps!

Thanks,
Valentin

[ESP_igrr]

Hi Valentin,

Many thanks for the files provided.

It's a bug in bootloader not calculating the number of cache pages that need to be mapped correctly.

In your case, the flash.rodata section starts at 0x3f400020 and has size 0x1fff0, so the end address should be 0x3f420010, and 3 64-kB pages should be mapped. In reality the final 0x10 bit (which ends up in the 3rd page) does not get mapped. The linker places __init_array into the end of .flash.rodata, so when the startup code tries to call init functions, it reads from unmapped region of memory. Normally this would result in "invalid cache access" exception, but in this case this exception is not yet enabled (happens a few lines later in startup code). Hence the difficult to debug panic handler output. The error does not happen often because .flash.rodata size needs to be within a pretty narrow range ([n*64kB - 0x1c, n*64kB - 0x4]).

This will be fixed in ESP-IDF soon, and a preliminary patch is attached.

[valentin]

Hi,

Many thanks for fixing the issue. I cannot apply it from the patch you sent, as I use esp-idf v3.0 and there is a big refactoring of the bootloader between the master branch and v3.0, so we will retrieve this patch with further esp-idf updates.

Any idea if this patch will be included in the official v3.1? And any rough estimate of this release?

Thanks,
Valentin

[ESP_igrr]

No, this patch will not make it into v3.1, which has already went through QA and is going to be released in a day or two.

We will have this fix in v3.1.1 and v3.0.5 bugfix releases though, both should happen in about a month.

There will also be a workaround for this in esptool.py, so that it does not generate problematic binaries which may trigger the issue with old bootloaders (for the OTA use case). It should appear in same bugfix releases.

[locomuco]

Hi there,

we're facing the same issue on 3.1 at the moment, which is expected reading this forum entry.

Is there a patch available targeting 3.1, or s there a plan to provide patches for the affected bootloader on 3.1?

Is there a esptool patch available upstream somewhere, that can be used?

BR,

Matthias