Hang and reboot during init when using core dump to flash and external PSRAM

[jcolebaker]

We have an ESP32 module with 2 MiB external PSRAM.

I have been storing core dumps to to flash, which was working well:

Code: Select all

CONFIG_ESP_COREDUMP_ENABLE=y
CONFIG_ESP_COREDUMP_ENABLE_TO_FLASH=y
...

I have now enabled the PSRAM:

Code: Select all

CONFIG_ESP32_SPIRAM_SUPPORT=y
CONFIG_SPIRAM_TYPE_AUTO=y
CONFIG_SPIRAM=y
CONFIG_SPIRAM_BOOT_INIT=y
CONFIG_SPIRAM_USE_CAPS_ALLOC=y
CONFIG_SPIRAM_MEMTEST=y
CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP=y
CONFIG_SPIRAM_BANKSWITCH_ENABLE=n
... Plus various other options

When I boot with these options, the boot process hangs for about 8 seconds during the ESP core dump initialization, then the device reboots with a watchdog timeout:

Code: Select all

I (1353) spiram: Adding pool of 2047K of external SPI memory to heap allocator
I (1362) spi_flash: detected chip: generic
I (1366) spi_flash: flash io: dio
I (1379) esp_core_dump_flash: Init core dump to flash
I (1393) esp_core_dump_flash: Found partition 'coredump' @ 50000 65536 bytes
ets Jul 29 2019 12:21:46

rst:0x10 (RTCWDT_RTC_RESET),boot:0x33 (SPI_FAST_FLASH_BOOT)

If I disable the core dump to flash option (CONFIG_ESP_COREDUMP_ENABLE_TO_FLASH=n), everything works well and the PSRAM can be used (but we lose the ability to recover core dump info from flash...).

What am I missing? Is it possible to use esp_core_dump_flash with external SPI RAM enabled?

[jcolebaker]

I've now found a work-around for this issue, but I'm not sure of the ultimate cause.

The problem is with code in the "espcoredump" component which calculates the checksum of the core dump when using flash storage ("esp_core_dump_image_check" function in "components\espcoredump\src\core_dump_flash.c"). This code is VERY slow, and takes ~10 seconds where it used to take maybe 200 mS without external RAM enabled. The delay was causing a watchdog timeout (and would be much too slow for our device boot up anyway).

The work-around is as follows:

* DISABLE core "dump check at boot" option: CONFIG_ESP_COREDUMP_CHECK_BOOT=n
* When attempting to check for a core dump from user code, I also call "esp_core_dump_image_check". I had to move this to a low-priority task so that it could happen in the background after app startup.
* Patched the ESP-IDF SDK to make the "coredump cache size" 128 (was 32): #define COREDUMP_CACHE_SIZE 128 in "components\espcoredump\include_core_dump\esp_core_dump_types.h". This made the checksum calculation significantly faster, but it was still quite slow.

I don't know why this particular flash read is so slow. I have other code which reads and writes significant data to/from flash partitions and it doesn't seem to be noticeably affected by enabling PSRAM.

[adokitkat]

Hello. Thank you for reporting this problem. I have created an issue about this in our internal issue tracker.

[ESP-erhankur]

jcolebaker, Sorry for a late response. Do you still have an issue with the PSRAM?

I did a try with the latest master and looks like it is fine.

Code: Select all

I (128) quad_psram: This chip is ESP32-D0WD
I (130) esp_psram: Found 8MB PSRAM device
I (130) esp_psram: Speed: 40MHz
I (130) esp_psram: PSRAM initialized, cache is in low/high (2-core) mode.
W (134) esp_psram: Virtual address not enough for PSRAM, map as much as we can. 4MB is mapped
I (142) cpu_start: Multicore app
I (1051) esp_psram: SPI SRAM memory test OK
I (1059) cpu_start: Pro cpu start user code
I (1059) cpu_start: cpu freq: 160000000 Hz
I (1059) app_init: Application information:
I (1059) app_init: Project name:     coredump-test
I (1064) app_init: App version:      1
I (1067) app_init: Compile time:     Mar 26 2025 16:43:20
I (1073) app_init: ELF file SHA256:  3bcee304d...
I (1077) app_init: ESP-IDF:          v5.5-dev-2715-ga45d713b03f
I (1083) efuse_init: Min chip rev:     v0.0
I (1087) efuse_init: Max chip rev:     v3.99 
I (1091) efuse_init: Chip rev:         v3.0
I (1095) heap_init: Initializing. RAM available for dynamic allocation:
I (1101) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1106) heap_init: At 3FFB35C8 len 0002CA38 (178 KiB): DRAM
I (1111) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1117) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1123) heap_init: At 4008EF84 len 0001107C (68 KiB): IRAM
I (1128) esp_psram: Adding pool of 4096K of PSRAM memory to heap allocator
I (1136) spi_flash: detected chip: generic
I (1138) spi_flash: flash io: dout
W (1141) spi_flash: Detected size(16384k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (1154) esp_core_dump_flash: Init core dump to flash
I (1168) esp_core_dump_flash: Found partition 'coredump' @ 187000 524288 bytes
I (1182) esp_core_dump_flash: Core dump data checksum is correct
I (1182) esp_core_dump_flash: Found core dump 9572 bytes in flash @ 0x187000
I (1185) main_task: Started on CPU0

Could you share the full logs from after the reset until the WDT reset? More details about your hardware would also be helpful. If you can share a reproducer app, it would help speed up understanding the issue.

[AshUK_]

Sorry to bump an old thread but I am also experiencing this with v5.4.2

Code: Select all

E (12103) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (12103) task_wdt:  - IDLE0 (CPU 0)
E (12103) task_wdt: Tasks currently running:
E (12103) task_wdt: CPU 0: main
E (12103) task_wdt: CPU 1: IDLE1
E (12103) task_wdt: Aborting.
E (12103) task_wdt: Print CPU 0 (current core) backtrace




Backtrace: 0x4000bfed:0x3ffbbb90 0x40093dd9:0x3ffbbba0 0x400831e9:0x3ffbbbd0 0x4008c3cf:0x3ffbbc00 0x4008bf8f:0x3ffbbc30 0x4014f10d:0x3ffbbc60 0x4014f4c3:0x3ffbbcc0 0x4014a8cc:0x3ffbbd00 0x4014a97c:0x3ffbbd30 0x400daa99:0x3ffbbd60 0x400e3e46:0x3ffbbe80 0x400dc168:0x3ffbbf10 0x401fd9b8:0x3ffbbf40 0x40093a8f:0x3ffbbf70
--- 0x4000bfed: _xtos_set_intlevel in ROM
--- 0x40093dd9: vPortClearInterruptMaskFromISR at /COMPONENT_FREERTOS_DIR/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:560
---  (inlined by) vPortExitCritical at /COMPONENT_FREERTOS_DIR/FreeRTOS-Kernel/portable/xtensa/port.c:514
--- 0x400831e9: vPortExitCriticalSafe at /COMPONENT_FREERTOS_DIR/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:594
---  (inlined by) esp_intr_noniram_enable at /COMPONENT_ESP_HW_SUPPORT_DIR/intr_alloc.c:951
--- 0x4008c3cf: spi_flash_enable_interrupts_caches_and_other_cpu at /COMPONENT_SPI_FLASH_DIR/cache_utils.c:246
--- 0x4008bf8f: s_do_mapping at /COMPONENT_ESP_MM_DIR/esp_mmu_map.c:436
--- 0x4014f10d: esp_mmu_map at /COMPONENT_ESP_MM_DIR/esp_mmu_map.c:575
--- 0x4014f4c3: spi_flash_mmap at /COMPONENT_SPI_FLASH_DIR/flash_mmap.c:85
--- 0x4014a8cc: esp_partition_mmap at /COMPONENT_ESP_PARTITION_DIR/partition_target.c:172
---  (inlined by) esp_partition_mmap at /COMPONENT_ESP_PARTITION_DIR/partition_target.c:154
--- 0x4014a97c: esp_partition_read at /COMPONENT_ESP_PARTITION_DIR/partition_target.c:50
--- 0x400daa99: esp_core_dump_image_check at /COMPONENT_ESPCOREDUMP_DIR/src/core_dump_flash.c:363
--- 0x400e3e46: load_core_dump at /COMPONENT_SYSTEM_DIR/src/system.c:290
---  (inlined by) system_init at /COMPONENT_SYSTEM_DIR/src/system.c:373
--- 0x400dc168: app_main at /COMPONENT_MAIN_DIR/main.c:41
--- 0x401fd9b8: main_task at /COMPONENT_FREERTOS_DIR/app_startup.c:208
--- 0x40093a8f: vPortTaskWrapper at /COMPONENT_FREERTOS_DIR/FreeRTOS-Kernel/portable/xtensa/port.c:139