SPI Flash Unmap Failure on 3.0.2

[brentru]

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 -> �[0;32mI (25) boot: ESP-IDF v4.4.3 2nd stage bootloader�[0m
11:20:24.792 -> �[0;32mI (25) boot: compile time 17:32:37�[0m
11:20:24.792 -> �[0;32mI (25) boot: chip revision: 0�[0m
11:20:24.792 -> �[0;32mI (26) qio_mode: Enabling default flash chip QIO�[0m
11:20:24.833 -> �[0;32mI (32) boot.esp32s3: Boot SPI Speed : 80MHz�[0m
11:20:24.833 -> �[0;32mI (37) boot.esp32s3: SPI Mode       : QIO�[0m
11:20:24.833 -> �[0;32mI (41) boot.esp32s3: SPI Flash Size : 4MB�[0m
11:20:24.833 -> �[0;32mI (46) boot: Enabling RNG early entropy source...�[0m
11:20:24.833 -> �[0;32mI (51) boot: Partition Table:�[0m
11:20:24.833 -> �[0;32mI (55) boot: ## Label            Usage          Type ST Offset   Length�[0m
11:20:24.833 -> �[0;32mI (62) boot:  0 nvs              WiFi data        01 02 00009000 00005000�[0m
11:20:24.833 -> �[0;32mI (70) boot:  1 otadata          OTA data         01 00 0000e000 00002000�[0m
11:20:24.845 -> �[0;32mI (77) boot:  2 ota_0            OTA app          00 10 00010000 00160000�[0m
11:20:24.845 -> �[0;32mI (85) boot:  3 ota_1            OTA app          00 11 00170000 00160000�[0m
11:20:24.845 -> �[0;32mI (92) boot:  4 uf2              factory app      00 00 002d0000 00040000�[0m
11:20:24.845 -> �[0;32mI (100) boot:  5 ffat             Unknown data     01 81 00310000 000f0000�[0m
11:20:24.882 -> �[0;32mI (107) boot: End of partition table�[0m
11:20:25.363 -> �[0;32mI (612) esp_image: segment 0: paddr=00010020 vaddr=3c040020 size=12528h ( 75048) map�[0m
11:20:25.363 -> �[0;32mI (629) esp_image: segment 1: paddr=00022550 vaddr=3fc92c00 size=02fdch ( 12252) load�[0m
11:20:25.399 -> �[0;32mI (631) esp_image: segment 2: paddr=00025534 vaddr=40374000 size=0aae4h ( 43748) load�[0m
11:20:25.399 -> �[0;32mI (643) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=30298h (197272) map�[0m
11:20:25.437 -> �[0;32mI (673) esp_image: segment 4: paddr=000602c0 vaddr=4037eae4 size=04030h ( 16432) load�[0m
11:20:25.437 -> �[0;32mI (682) boot: Loaded app from partition at offset 0x10000�[0m
11:20:25.437 -> �[0;32mI (682) boot: Disabling RNG early entropy source...�[0m
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 -> �[0;32mI (29) boot: ESP-IDF v4.4.3 2nd stage bootloader�[0m
11:20:25.992 -> �[0;32mI (29) boot: compile time 17:32:37�[0m
11:20:25.992 -> �[0;32mI (29) boot: chip revision: 0�[0m
11:20:25.992 -> �[0;32mI (31) qio_mode: Enabling default flash chip QIO�[0m
11:20:25.992 -> �[0;32mI (36) boot.esp32s3: Boot SPI Speed : 80MHz�[0m
11:20:25.992 -> �[0;32mI (41) boot.esp32s3: SPI Mode       : QIO�[0m
11:20:25.992 -> �[0;32mI (46) boot.esp32s3: SPI Flash Size : 4MB�[0m
11:20:25.992 -> �[0;32mI (50) boot: Enabling RNG early entropy source...�[0m
11:20:26.030 -> �[0;32mI (56) boot: Partition Table:�[0m
11:20:26.030 -> �[0;32mI (59) boot: ## Label            Usage          Type ST Offset   Length�[0m
11:20:26.030 -> �[0;32mI (67) boot:  0 nvs              WiFi data        01 02 00009000 00005000�[0m
11:20:26.030 -> �[0;32mI (74) boot:  1 otadata          OTA data         01 00 0000e000 00002000�[0m
11:20:26.030 -> �[0;32mI (81) boot:  2 ota_0            OTA app          00 10 00010000 00160000�[0m
11:20:26.030 -> �[0;32mI (89) boot:  3 ota_1            OTA app          00 11 00170000 00160000�[0m
11:20:26.068 -> �[0;32mI (96) boot:  4 uf2              factory app      00 00 002d0000 00040000�[0m
11:20:26.068 -> �[0;32mI (104) boot:  5 ffat             Unknown data     01 81 00310000 000f0000�[0m
11:20:26.068 -> �[0;32mI (111) boot: End of partition table�[0m
11:20:26.574 -> �[0;32mI (616) esp_image: segment 0: paddr=00010020 vaddr=3c040020 size=12528h ( 75048) map�[0m
11:20:26.574 -> �[0;32mI (628) esp_image: segment 1: paddr=00022550 vaddr=3fc92c00 size=02fdch ( 12252) load�[0m
11:20:26.574 -> �[0;32mI (630) esp_image: segment 2: paddr=00025534 vaddr=40374000 size=0aae4h ( 43748) load�[0m
11:20:26.611 -> �[0;32mI (642) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=30298h (197272) map�[0m
11:20:26.611 -> �[0;32mI (672) esp_image: segment 4: paddr=000602c0 vaddr=4037eae4 size=04030h ( 16432) load�[0m
11:20:26.648 -> �[0;32mI (681) boot: Loaded app from partition at offset 0x10000�[0m
11:20:26.648 -> �[0;32mI (681) boot: Disabling RNG early entropy source...�[0m
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]

cc @hathach @ladyada

[ladyada]

@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]

@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]

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]

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

[me-no-dev]

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]

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