search

espressif / arduino-esp32

Arduino core for the ESP32
GNU Lesser General Public License v2.1
12.96k stars 7.29k forks source link

SPI Flash Unmap Failure on 3.0.2 #9936

Open brentru opened 1 week ago

brentru commented 1 week ago

Board

Adafruit ESP32-S3 Reverse TFT Feather

Device Description

Adafruit ESP32-S3 Reverse TFT Feather - 4MB Flash, 2MB PSRAM, STEMMA QT

Hardware Configuration

Nothing is connected to the board

Version

latest master (checkout manually)

IDE Name

Arduino IDE

Operating System

macOS

Flash frequency

QIO 80MHZ

PSRAM enabled

yes

Upload speed

115200

Description

Adafruit ESP32-S3 Reverse TFT Feather (w/TinyUF2 (4MB partition scheme)) fails to load the Blink sketch. Instead of loading Blink, it appears as a BOOT drive. The debug logs

The core issue stems from esp_mmu_unmap and spi_flash_munmap emitting failures:

11:20:25.849 -> [  1087][I][esp32-hal-psram.c:90] psramInit(): PSRAM enabled
11:20:25.849 -> E (1341) mmap: esp_mmu_unmap(595): munmap target pointer is outside external memory regions
11:20:25.849 -> 
11:20:25.883 -> assert failed: spi_flash_munmap flash_mmap.c:241 (0 && "invalid handle, or handle already unmapped")
11:20:25.883 ->

Sketch

Generic Arduino Blink Sketch w/TinyUF2 (4MB partition scheme)

/*
  Blink

  Turns an LED on for one second, then off for one second, repeatedly.

  Most Arduinos have an on-board LED you can control. On the UNO, MEGA and ZERO
  it is attached to digital pin 13, on MKR1000 on pin 6. LED_BUILTIN is set to
  the correct LED pin independent of which board is used.
  If you want to know what pin the on-board LED is connected to on your Arduino
  model, check the Technical Specs of your board at:
  https://www.arduino.cc/en/Main/Products

  modified 8 May 2014
  by Scott Fitzgerald
  modified 2 Sep 2016
  by Arturo Guadalupi
  modified 8 Sep 2016
  by Colby Newman

  This example code is in the public domain.

  https://www.arduino.cc/en/Tutorial/BuiltInExamples/Blink
*/

// the setup function runs once when you press reset or power the board
void setup() {
  // initialize digital pin LED_BUILTIN as an output.
  pinMode(LED_BUILTIN, OUTPUT);
}

// the loop function runs over and over again forever
void loop() {
  digitalWrite(LED_BUILTIN, HIGH);   // turn the LED on (HIGH is the voltage level)
  delay(1000);                       // wait for a second
  digitalWrite(LED_BUILTIN, LOW);    // turn the LED off by making the voltage LOW
  delay(1000);                       // wait for a second
}

Debug Message

VERBOSE debug:

11:20:24.792 -> ESP-ROM:esp32s3-20210327
11:20:24.792 -> Build:Mar 27 2021
11:20:24.792 -> rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
11:20:24.792 -> SPIWP:0xee
11:20:24.792 -> mode:DIO, clock div:1
11:20:24.792 -> load:0x3fcd0108,len:0x1634
11:20:24.792 -> load:0x403b6000,len:0xed4
11:20:24.792 -> load:0x403ba000,len:0x31c8
11:20:24.792 -> entry 0x403b632c
11:20:24.792 -> I (25) boot: ESP-IDF v4.4.3 2nd stage bootloader
11:20:24.792 -> I (25) boot: compile time 17:32:37
11:20:24.792 -> I (25) boot: chip revision: 0
11:20:24.792 -> I (26) qio_mode: Enabling default flash chip QIO
11:20:24.833 -> I (32) boot.esp32s3: Boot SPI Speed : 80MHz
11:20:24.833 -> I (37) boot.esp32s3: SPI Mode       : QIO
11:20:24.833 -> I (41) boot.esp32s3: SPI Flash Size : 4MB
11:20:24.833 -> I (46) boot: Enabling RNG early entropy source...
11:20:24.833 -> I (51) boot: Partition Table:
11:20:24.833 -> I (55) boot: ## Label            Usage          Type ST Offset   Length
11:20:24.833 -> I (62) boot:  0 nvs              WiFi data        01 02 00009000 00005000
11:20:24.833 -> I (70) boot:  1 otadata          OTA data         01 00 0000e000 00002000
11:20:24.845 -> I (77) boot:  2 ota_0            OTA app          00 10 00010000 00160000
11:20:24.845 -> I (85) boot:  3 ota_1            OTA app          00 11 00170000 00160000
11:20:24.845 -> I (92) boot:  4 uf2              factory app      00 00 002d0000 00040000
11:20:24.845 -> I (100) boot:  5 ffat             Unknown data     01 81 00310000 000f0000
11:20:24.882 -> I (107) boot: End of partition table
11:20:25.363 -> I (612) esp_image: segment 0: paddr=00010020 vaddr=3c040020 size=12528h ( 75048) map
11:20:25.363 -> I (629) esp_image: segment 1: paddr=00022550 vaddr=3fc92c00 size=02fdch ( 12252) load
11:20:25.399 -> I (631) esp_image: segment 2: paddr=00025534 vaddr=40374000 size=0aae4h ( 43748) load
11:20:25.399 -> I (643) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=30298h (197272) map
11:20:25.437 -> I (673) esp_image: segment 4: paddr=000602c0 vaddr=4037eae4 size=04030h ( 16432) load
11:20:25.437 -> I (682) boot: Loaded app from partition at offset 0x10000
11:20:25.437 -> I (682) boot: Disabling RNG early entropy source...
11:20:25.437 -> [   701][D][esp32-hal-tinyusb.c:772] tinyusb_enable_interface2(): Interface CDC enabled
11:20:25.475 -> [   709][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x42006838
11:20:25.475 -> [   720][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x42006804
11:20:25.475 -> [   731][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x420067d0
11:20:25.513 -> [   742][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x4200679c
11:20:25.513 -> [   754][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x42006838
11:20:25.513 -> [   765][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x42006804
11:20:25.513 -> [   776][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x420067d0
11:20:25.551 -> [   788][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x4200679c
11:20:25.551 -> [   799][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x42006838
11:20:25.551 -> [   810][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x42006804
11:20:25.589 -> [   822][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x420067d0
11:20:25.589 -> [   833][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x4200679c
11:20:25.589 -> E (845) esp_core_dump_flash: No core dump partition found!
11:20:25.589 -> E (845) esp_core_dump_flash: No core dump partition found!
11:20:25.589 -> [   846][D][esp32-hal-tinyusb.c:655] tinyusb_load_enabled_interfaces(): Load Done: if_num: 2, descr_len: 75, if_mask: 0x10
11:20:25.849 -> [  1087][I][esp32-hal-psram.c:90] psramInit(): PSRAM enabled
11:20:25.849 -> E (1341) mmap: esp_mmu_unmap(595): munmap target pointer is outside external memory regions
11:20:25.849 -> 
11:20:25.883 -> assert failed: spi_flash_munmap flash_mmap.c:241 (0 && "invalid handle, or handle already unmapped")
11:20:25.883 -> 
11:20:25.883 -> 
11:20:25.883 -> Backtrace: 0x40376dce:0x3fcf4800 0x4037b1dd:0x3fcf4820 0x40380f81:0x3fcf4840 0x4200b363:0x3fcf4970 0x4200ae99:0x3fcf4990 0x4200af9d:0x3fcf49b0 0x4200b237:0x3fcf49e0 0x42002699:0x3fcf4a40 0x42003b63:0x3fcf4a80 0x4202fb6d:0x3fcf4ab0 0x4037deca:0x3fcf4af0
11:20:25.918 -> 
11:20:25.918 -> 
11:20:25.918 -> 
11:20:25.918 -> 
11:20:25.918 -> ELF file SHA256: 9cb9626fd8b9782e
11:20:25.918 -> 
11:20:25.918 -> E (1167) esp_core_dump_flash: Core dump flash config is corrupted! CRC=0x7bd5c66f instead of 0x0
11:20:25.956 -> E (1176) esp_core_dump_elf: Elf write init failed!
11:20:25.956 -> E (1180) esp_core_dump_common: Core dump write failed with error=-1
11:20:25.956 -> Rebooting...
11:20:25.956 -> ESP-ROM:esp32s3-20210327
11:20:25.956 -> Build:Mar 27 2021
11:20:25.956 -> rst:0xc (RTC_SW_CPU_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
11:20:25.956 -> Saved PC:0x403773e1
11:20:25.956 -> SPIWP:0xee
11:20:25.956 -> mode:DIO, clock div:1
11:20:25.956 -> load:0x3fcd0108,len:0x1634
11:20:25.956 -> load:0x403b6000,len:0xed4
11:20:25.992 -> load:0x403ba000,len:0x31c8
11:20:25.992 -> entry 0x403b632c
11:20:25.992 -> I (29) boot: ESP-IDF v4.4.3 2nd stage bootloader
11:20:25.992 -> I (29) boot: compile time 17:32:37
11:20:25.992 -> I (29) boot: chip revision: 0
11:20:25.992 -> I (31) qio_mode: Enabling default flash chip QIO
11:20:25.992 -> I (36) boot.esp32s3: Boot SPI Speed : 80MHz
11:20:25.992 -> I (41) boot.esp32s3: SPI Mode       : QIO
11:20:25.992 -> I (46) boot.esp32s3: SPI Flash Size : 4MB
11:20:25.992 -> I (50) boot: Enabling RNG early entropy source...
11:20:26.030 -> I (56) boot: Partition Table:
11:20:26.030 -> I (59) boot: ## Label            Usage          Type ST Offset   Length
11:20:26.030 -> I (67) boot:  0 nvs              WiFi data        01 02 00009000 00005000
11:20:26.030 -> I (74) boot:  1 otadata          OTA data         01 00 0000e000 00002000
11:20:26.030 -> I (81) boot:  2 ota_0            OTA app          00 10 00010000 00160000
11:20:26.030 -> I (89) boot:  3 ota_1            OTA app          00 11 00170000 00160000
11:20:26.068 -> I (96) boot:  4 uf2              factory app      00 00 002d0000 00040000
11:20:26.068 -> I (104) boot:  5 ffat             Unknown data     01 81 00310000 000f0000
11:20:26.068 -> I (111) boot: End of partition table
11:20:26.574 -> I (616) esp_image: segment 0: paddr=00010020 vaddr=3c040020 size=12528h ( 75048) map
11:20:26.574 -> I (628) esp_image: segment 1: paddr=00022550 vaddr=3fc92c00 size=02fdch ( 12252) load
11:20:26.574 -> I (630) esp_image: segment 2: paddr=00025534 vaddr=40374000 size=0aae4h ( 43748) load
11:20:26.611 -> I (642) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=30298h (197272) map
11:20:26.611 -> I (672) esp_image: segment 4: paddr=000602c0 vaddr=4037eae4 size=04030h ( 16432) load
11:20:26.648 -> I (681) boot: Loaded app from partition at offset 0x10000
11:20:26.648 -> I (681) boot: Disabling RNG early entropy source...
11:20:26.648 -> [   700][D][esp32-hal-tinyusb.c:772] tinyusb_enable_interface2(): Interface CDC enabled
11:20:26.648 -> [   708][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x42006838
11:20:26.686 -> [   719][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x42006804
11:20:26.686 -> [   730][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x420067d0
11:20:26.686 -> [   742][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x4200679c
11:20:26.686 -> [   753][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x42006838
11:20:26.720 -> [   764][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x42006804
11:20:26.720 -> [   775][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x420067d0
11:20:26.720 -> [   787][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x4200679c
11:20:26.758 -> [   798][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RX (2) successfully set to 0x42006838
11:20:26.758 -> [   809][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_TX (3) successfully set to 0x42006804
11:20:26.758 -> [   821][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_CTS (4) successfully set to 0x420067d0
11:20:26.796 -> [   832][V][esp32-hal-periman.c:235] perimanSetBusDeinit(): Deinit function for type UART_RTS (5) successfully set to 0x4200679c
11:20:26.796 -> E (843) esp_core_dump_flash: No core dump partition found!
11:20:26.796 -> E (844) esp_core_dump_flash: No core dump partition found!
11:20:26.796 -> [   845][D][esp32-hal-tinyusb.c:655] tinyusb_load_enabled_interfaces(): Load Done: if_num: 2, descr_len: 75, if_mask: 0x10
11:20:27.048 -> [  1086][I][esp32-hal-psram.c:90] psramInit(): PSRAM enabled
11:20:27.048 -> E (1340) mmap: esp_mmu_unmap(595): munmap target pointer is outside external memory regions
11:20:27.048 -> 
11:20:27.086 -> assert failed: spi_flash_munmap flash_mmap.c:241 (0 && "invalid handle, or handle already unmapped")
11:20:27.086 -> 
11:20:27.086 -> 
11:20:27.086 -> Backtrace: 0x40376dce:0x3fcf4800 0x4037b1dd:0x3fcf4820 0x40380f81:0x3fcf4840 0x4200b363:0x3fcf4970 0x4200ae99:0x3fcf4990 0x4200af9d:0x3fcf49b0 0x4200b237:0x3fcf49e0 0x42002699:0x3fcf4a40 0x42003b63:0x3fcf4a80 0x4202fb6d:0x3fcf4ab0 0x4037deca:0x3fcf4af0
11:20:27.124 -> 
11:20:27.124 -> 
11:20:27.124 -> 
11:20:27.124 -> 
11:20:27.124 -> ELF file SHA256: 9cb9626fd8b9782e
11:20:27.124 -> 
11:20:27.124 -> E (1166) esp_core_dump_flash: Core dump flash config is corrupted! CRC=0x7bd5c66f instead of 0x0
11:20:27.124 -> E (1175) esp_core_dump_elf: Elf write init failed!
11:20:27.124 -> E (1179) esp_core_dump_common: Core dump write failed with error=-1
11:20:27.162 -> Rebooting...

Backtrace:


Decoding stack results
0x40376dce: panic_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/panic.c line 466
0x4037b1dd: esp_system_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/port/esp_system_chip.c line 84
0x40380f81: __assert_func at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/assert.c line 81
0x4200b363: spi_flash_munmap at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/spi_flash/flash_mmap.c line 241
0x4200ae99: esp_partition_munmap at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_partition/partition_target.c line 173
0x4200af9d: read_otadata at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/app_update/esp_ota_ops.c line 97
0x4200b237: esp_ota_get_state_partition at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/app_update/esp_ota_ops.c line 836
0x42002699: initArduino at /Users/brentrubell/Library/Arduino15/packages/esp32/hardware/esp32/3.0.2/cores/esp32/esp32-hal-misc.c line 262
0x42003b63: app_main() at /Users/brentrubell/Library/Arduino15/packages/esp32/hardware/esp32/3.0.2/cores/esp32/main.cpp line 104
0x4202fb6d: main_task at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/app_startup.c line 208
0x4037deca: vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c line 162


### Other Steps to Reproduce

_No response_

### I have checked existing issues, online documentation and the Troubleshooting Guide

- [X] I confirm I have checked existing issues, online documentation and Troubleshooting guide.
me-no-dev commented 1 week ago

cc @hathach @ladyada

ladyada commented 1 week ago

@me-no-dev yes brent works for adafruit, we dont know what it is and hope you have some ideas since the board used to work

me-no-dev commented 1 week ago

@brentru @ladyada is this one particular board or all such boards? OTA partition is not overwritten?

Code that breaks is part of OTA Rollback support and is trying to get the OTA Data partition to read the state of the partition that is trying to boot. This is nothing special and has worked fine since was added. Can you try with earlier core version? We merged some IDF changes in 3.0.2 that were not in previous 3.0.x

brentru commented 1 week ago

is this one particular board or all such boards?

This is only on the Feather ESP32-S3 Reverse TFT.

OTA partition is not overwritten?

I am unsure if the OTA partition is not overwritten. Could you suggest a method of verifying this?

Can you try with earlier core version? We merged some IDF changes in 3.0.2 that were not in previous 3.0.x

Sure, I'll try with 3.0.0 and 3.0.1 and provide info from trying this in a follow-up comment.

brentru commented 1 week ago

@me-no-dev I installed 3.0.1 and can confirm this does not happen, it blinks as expected.

me-no-dev commented 1 week ago

I'll try to replicate tomorrow somehow. Any pointers on using a regular S3 would be welcome. I also notice that the bootloader is still from 2.0.x (IDF 4.4). Not sure if this is connected, but a thing to look into.

me-no-dev commented 5 days ago

I can confirm the issue. It's not just that board, but any S3 with enabled QSPI PSRAM. No PSRAM or OPI PSRAM works fine. 3.0.1 works also as expected, so issue was recently introduced into IDF release/v5.1 branch. Will track this to be fixed before we release another version

me-no-dev commented 5 days ago

We triggered this bug by implementing this feature request.

I have found that it's necessary to have all of the following conditions to trigger it:

  1. ESP32-S3 NxR2
  2. OTA partition scheme used
  3. COREDUMP to Flash to be enabled
  4. QPI SPIRAM to be initialized in app_main
  5. App RollBack enabled and checked after PSRAM is initialized

Checking for rollback before initializing PSRAM also works, so that is probably one solution to try. Still unsure if this is not going to cause other problems with OTA.

me-no-dev commented 4 days ago

Bug has been found by the IDF team and fix has been proposed. @brentru can you please replace your libs with the ones from this build and see if issue is resolved. Would also really appreciate if you test other boards/chips.

brentru commented 4 days ago

@brentru can you please replace your libs with the ones from this build and see if issue is resolved. Would also really appreciate if you test other boards/chips.

Sure - where should I put these libraries?

me-no-dev commented 1 day ago

where should I put these libraries?

Depends how you use the core. If it's from Git, then it will be in ../Arduino/hardware/espressif/esp32/tools/esp32-arduino-libs folder. If you are using the boards manager, then it will be in ../Arduino15/packages/esp32/tools/esp32-arduino-libs folder. Where the dots are depends on which OS you are running on.

brentru commented 1 day ago

@me-no-dev I re-tested the example sketch (Blink) with the same hardware and inspected the IDF output. It's functioning correctly and the PSRAM is initializing successfully, too: [ 1087][I][esp32-hal-psram.c:90] psramInit(): PSRAM enabled

Would also really appreciate if you test other boards/chips. Okay! I tested Blink on the following

  • Adafruit Feather ESP32-S3 Rev TFT Feather
  • Adafruit QT Py ESP32-S3
  • Adafruit QT Py ESP32
me-no-dev commented 1 day ago

Thanks @brentru! will merge the fix then :)