Coredump into flash fails when PSRAM is enabled in esp32s2
Posted: Mon Jun 28, 2021 3:50 pm
I am facing memory corruption while coredump and esp32s2 keeps on restarting on giving Cache Error. See below log for more information.
To reproduce the issue, I have disabled watchdog feed for one task and after watchdog timeout, system aborted and tried to write to coredump into flash. While writing coredump into flash, memory corrupted (which I guess due to SPIRAM, I am using PSRAM extensively in my application). See below log for more information. Did anyone face the same issue?
To reproduce the issue, I have disabled watchdog feed for one task and after watchdog timeout, system aborted and tried to write to coredump into flash. While writing coredump into flash, memory corrupted (which I guess due to SPIRAM, I am using PSRAM extensively in my application). See below log for more information. Did anyone face the same issue?
E (121523) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (121523) task_wdt: - heartbeat_task (CPU 0)
E (121523) task_wdt: Tasks currently running:
E (121523) task_wdt: CPU 0: IDLE
E (121523) task_wdt: Aborting.
abort() was called at PC 0x40114e04 on core 0
0x40114e04: task_wdt_isr at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_common/src/task_wdt.c:182 (discriminator 1)
Backtrace:0x4002d213:0x3ffc6c70 0x4002dda5:0x3ffc6c90 0x40034f0e:0x3ffc6cb0 0x40114e04:0x3ffc6d20 0x40026b32:0x3ffc6d40 0x4001a8d1:0x3ff9fcf0 |<-CORRUPTED
0x4002d213: panic_abort at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/panic.c:356
0x4002dda5: esp_system_abort at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/system_api.c:112
0x40034f0e: abort at /home/nileshkumar/development/gw-mesh/esp-idf/components/newlib/abort.c:46
0x40114e04: task_wdt_isr at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_common/src/task_wdt.c:182 (discriminator 1)
0x40026b32: _xt_lowint1 at /home/nileshkumar/development/gw-mesh/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1105
ELF file SHA256: 8d9da599faabb421
I (26368) esp_core_dump_flash: Save core dump to flash...
I (26374) esp_core_dump_flash: Erase flash 24576 bytes @ 0x27c000
abort() was called at PC 0x40114e04 on core 0
0x40114e04: task_wdt_isr at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_common/src/task_wdt.c:182 (discriminator 1)
Backtrace:0x4001abf7:0x3ffc69a0 0x4008a7f8:0x3ffc69b0 0x4008b486:0x3ffc69e0 0x4008ba39:0x3ffc6a20 0x4008bc17:0x3ffc6a70 0x4008bd99:0x3ffc6a90 0x4008a742:0x3ffc6ac0 0x4008abac:0x3ffc6ae0 0x4002d38a:0x3ffc6b00 0x4002da81:0x3ffc6b70 0x4002dadd:0x3ffc6bc0 0x40026a52:0x3ffc6be0 0x4002d213:0x3ffc6c70 0x4002dda5:0x3ffc6c90 0x40034f0e:0x3ffc6cb0 0x40114e04:0x3ffc6d20 0x40026b32:0x3ffc6d40 0x4001a8d1:0x3ff9fcf0 |<-CORRUPTED
0x4008a7f8: esp_core_dump_flash_write_data at /home/nileshkumar/development/gw-mesh/esp-idf/components/espcoredump/src/core_dump_flash.c:115
0x4008b486: elf_add_segment at /home/nileshkumar/development/gw-mesh/esp-idf/components/espcoredump/src/core_dump_elf.c:186
0x4008ba39: elf_write_tasks_data at /home/nileshkumar/development/gw-mesh/esp-idf/components/espcoredump/src/core_dump_elf.c:457
0x4008bc17: esp_core_dump_do_write_elf_pass at /home/nileshkumar/development/gw-mesh/esp-idf/components/espcoredump/src/core_dump_elf.c:544 (discriminator 2)
0x4008bd99: esp_core_dump_write_elf at /home/nileshkumar/development/gw-mesh/esp-idf/components/espcoredump/src/core_dump_elf.c:626
0x4008a742: esp_core_dump_write at /home/nileshkumar/development/gw-mesh/esp-idf/components/espcoredump/src/core_dump_common.c:283 (discriminator 3)
0x4008abac: esp_core_dump_to_flash at /home/nileshkumar/development/gw-mesh/esp-idf/components/espcoredump/src/core_dump_flash.c:335
0x4002d38a: esp_panic_handler at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/panic.c:311
0x4002da81: panic_handler at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/port/panic_handler.c:200
0x4002dadd: xt_unhandled_exception at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/port/panic_handler.c:214
0x40026a52: _xt_user_exc at /home/nileshkumar/development/gw-mesh/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:697
0x4002d213: panic_abort at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/panic.c:356
0x4002dda5: esp_system_abort at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/system_api.c:112
0x40034f0e: abort at /home/nileshkumar/development/gw-mesh/esp-idf/components/newlib/abort.c:46
0x40114e04: task_wdt_isr at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_common/src/task_wdt.c:182 (discriminator 1)
0x40026b32: _xt_lowint1 at /home/nileshkumar/development/gw-mesh/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1105
ELF file SHA256: 8d9da599faabb421
Re-entered core dump! Exception happened during core dump!
Rebooting...
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0xc (RTC_SW_CPU_RST),boot:0xb (SPI_FAST_FLASH_BOOT)
Saved PC:0x400267b8
0x400267b8: esp_restart_noos at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp32s2/system_api_esp32s2.c:109 (discriminator 1)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x18bc
load:0x4004c000,len:0x9d8
load:0x40050000,len:0x2ebc
entry 0x4004c1ec
I (46) boot: ESP-IDF v4.4-dev-4-g73db14240-dirty 2nd stage bootloader
I (46) boot: compile time 17:27:34
I (46) boot: chip revision: 0
I (50) boot.esp32s2: SPI Speed : 80MHz
I (54) boot.esp32s2: SPI Mode : DIO
I (59) boot.esp32s2: SPI Flash Size : 4MB
I (64) boot: Enabling RNG early entropy source...
I (69) boot: Partition Table:
I (73) boot: ## Label Usage Type ST Offset Length
I (80) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (88) boot: 1 otadata OTA data 01 00 0000f000 00002000
I (95) boot: 2 phy_init RF data 01 01 00011000 00001000
I (103) boot: 3 ota_0 OTA app 00 10 00020000 0012c000
I (110) boot: 4 ota_1 OTA app 00 11 00150000 0012c000
I (118) boot: 5 coredump Unknown data 01 03 0027c000 00010000
I (125) boot: End of partition table
I (129) esp_image: segment 0: paddr=00020020 vaddr=3f000020 size=35e68h (220776) map
I (180) esp_image: segment 1: paddr=00055e90 vaddr=3ffc62d0 size=056a4h ( 22180) load
I (185) esp_image: segment 2: paddr=0005b53c vaddr=40024000 size=04adch ( 19164) load
I (190) esp_image: segment 3: paddr=00060020 vaddr=40080020 size=96f8ch (618380) map
I (312) esp_image: segment 4: paddr=000f6fb4 vaddr=40028adc size=0d7e8h ( 55272) load
I (336) boot: Loaded app from partition at offset 0x20000
I (336) boot: Disabling RNG early entropy source...
I (347) cache: Instruction cache : size 8KB, 4Ways, cache line size 32Byte
I (347) cache: Data cache : size 8KB, 4Ways, cache line size 32Byte
I (353) spiram: Found 16MBit SPI RAM device
I (358) spiram: SPI RAM mode: sram 40m
I (362) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (369) cpu_start: Pro cpu up.
I (783) spiram: SPI SRAM memory test OK
Guru Meditation Error: Core 0 panic'ed (Cache error).
Core 0 register dump:
PC : 0x40112879 PS : 0x00060d34 A0 : 0x800aef36 A1 : 0x3fffe280
0x40112879: xt_ints_on at /home/nileshkumar/development/gw-mesh/esp-idf/components/xtensa/xtensa_intr_asm.S:164
A2 : 0x02000000 A3 : 0x00000000 A4 : 0x02000000 A5 : 0x00000004
A6 : 0x000000c0 A7 : 0x00000000 A8 : 0x3ffffd70 A9 : 0x3fffe240
A10 : 0x007dff2d A11 : 0x00000030 A12 : 0x00000000 A13 : 0x3ffcc2b0
A14 : 0x00000000 A15 : 0x00000000 SAR : 0x00000007 EXCCAUSE: 0x00000007
EXCVADDR: 0x00000000 LBEG : 0x00000000 LEND : 0x3ffcc2b0 LCOUNT : 0x400256f0
0x400256f0: xt_highint4 at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/port/soc/esp32s2/dport_panic_highint_hdl.S:58
Backtrace:0x40112876:0x3fffe280 0x400aef33:0x3fffe290 0x4008becb:0x3fffe2b0 0x4008c67a:0x3fffe2d0 0x400256b6:0x3fffe310 0x40050e25:0x3fffe330 0x40051281:0x3fffe370 0x4004c23d:0x3fffe4a0 0x40011371:0x3fffe560 0x4000f788:0x3fffe6f0 0x400072a5:0x3fffe710
0x40112876: xt_ints_on at /home/nileshkumar/development/gw-mesh/esp-idf/components/xtensa/xtensa_intr_asm.S:163
0x400aef33: intr_cntrl_ll_enable_interrupts at /home/nileshkumar/development/gw-mesh/esp-idf/components/hal/esp32s2/include/hal/interrupt_controller_ll.h:33
(inlined by) interrupt_controller_hal_enable_interrupts at /home/nileshkumar/development/gw-mesh/esp-idf/components/hal/include/hal/interrupt_controller_hal.h:125
(inlined by) esp_intr_enable_source at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/intr_alloc.c:833
0x4008becb: esp_memprot_intr_init at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp32s2/memprot.c:147
0x4008c67a: esp_memprot_set_prot at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp32s2/memprot.c:691
0x400256b6: call_start_cpu0 at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/port/cpu_start.c:469
ELF file SHA256: 8d9da599faabb421
E (904) esp_core_dump_flash: Core dump flash config is corrupted! CRC=0x7bd5c66f instead of 0x0
Rebooting...
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0xc (RTC_SW_CPU_RST),boot:0xb (SPI_FAST_FLASH_BOOT)
Saved PC:0x400267b8
0x400267b8: esp_restart_noos at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp32s2/system_api_esp32s2.c:109 (discriminator 1)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x18bc
load:0x4004c000,len:0x9d8
load:0x40050000,len:0x2ebc
entry 0x4004c1ec
I (46) boot: ESP-IDF v4.4-dev-4-g73db14240-dirty 2nd stage bootloader
I (46) boot: compile time 17:27:34
I (46) boot: chip revision: 0
I (50) boot.esp32s2: SPI Speed : 80MHz
I (54) boot.esp32s2: SPI Mode : DIO
I (59) boot.esp32s2: SPI Flash Size : 4MB
I (64) boot: Enabling RNG early entropy source...
I (69) boot: Partition Table:
I (73) boot: ## Label Usage Type ST Offset Length
I (80) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (88) boot: 1 otadata OTA data 01 00 0000f000 00002000
I (95) boot: 2 phy_init RF data 01 01 00011000 00001000
I (103) boot: 3 ota_0 OTA app 00 10 00020000 0012c000
I (110) boot: 4 ota_1 OTA app 00 11 00150000 0012c000
I (118) boot: 5 coredump Unknown data 01 03 0027c000 00010000
I (125) boot: End of partition table
I (129) esp_image: segment 0: paddr=00020020 vaddr=3f000020 size=35e68h (220776) map
I (180) esp_image: segment 1: paddr=00055e90 vaddr=3ffc62d0 size=056a4h ( 22180) load
I (185) esp_image: segment 2: paddr=0005b53c vaddr=40024000 size=04adch ( 19164) load
I (190) esp_image: segment 3: paddr=00060020 vaddr=40080020 size=96f8ch (618380) map
I (312) esp_image: segment 4: paddr=000f6fb4 vaddr=40028adc size=0d7e8h ( 55272) load
I (336) boot: Loaded app from partition at offset 0x20000
I (336) boot: Disabling RNG early entropy source...
I (347) cache: Instruction cache : size 8KB, 4Ways, cache line size 32Byte
I (347) cache: Data cache : size 8KB, 4Ways, cache line size 32Byte
I (353) spiram: Found 16MBit SPI RAM device
I (358) spiram: SPI RAM mode: sram 40m
I (362) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (369) cpu_start: Pro cpu up.
I (783) spiram: SPI SRAM memory test OK
Guru Meditation Error: Core 0 panic'ed (Cache error).
Core 0 register dump:
PC : 0x40112879 PS : 0x00060d34 A0 : 0x800aef36 A1 : 0x3fffe280
0x40112879: xt_ints_on at /home/nileshkumar/development/gw-mesh/esp-idf/components/xtensa/xtensa_intr_asm.S:164
A2 : 0x02000000 A3 : 0x00000000 A4 : 0x02000000 A5 : 0x00000004
A6 : 0x000000c0 A7 : 0x00000000 A8 : 0x3ffffd70 A9 : 0x3fffe240
A10 : 0x007dff2d A11 : 0x00000030 A12 : 0x00000000 A13 : 0x3ffcc2b0
A14 : 0x00000000 A15 : 0x00000000 SAR : 0x00000007 EXCCAUSE: 0x00000007
EXCVADDR: 0x00000000 LBEG : 0x00000000 LEND : 0x3ffcc2b0 LCOUNT : 0x400256f0
0x400256f0: xt_highint4 at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/port/soc/esp32s2/dport_panic_highint_hdl.S:58
Backtrace:0x40112876:0x3fffe280 0x400aef33:0x3fffe290 0x4008becb:0x3fffe2b0 0x4008c67a:0x3fffe2d0 0x400256b6:0x3fffe310 0x40050e25:0x3fffe330 0x40051281:0x3fffe370 0x4004c23d:0x3fffe4a0 0x40011371:0x3fffe560 0x4000f788:0x3fffe6f0 0x400072a5:0x3fffe710
0x40112876: xt_ints_on at /home/nileshkumar/development/gw-mesh/esp-idf/components/xtensa/xtensa_intr_asm.S:163
0x400aef33: intr_cntrl_ll_enable_interrupts at /home/nileshkumar/development/gw-mesh/esp-idf/components/hal/esp32s2/include/hal/interrupt_controller_ll.h:33
(inlined by) interrupt_controller_hal_enable_interrupts at /home/nileshkumar/development/gw-mesh/esp-idf/components/hal/include/hal/interrupt_controller_hal.h:125
(inlined by) esp_intr_enable_source at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/intr_alloc.c:833
0x4008becb: esp_memprot_intr_init at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp32s2/memprot.c:147
0x4008c67a: esp_memprot_set_prot at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp32s2/memprot.c:691
0x400256b6: call_start_cpu0 at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp_system/port/cpu_start.c:469
ELF file SHA256: 8d9da599faabb421
E (904) esp_core_dump_flash: Core dump flash config is corrupted! CRC=0x7bd5c66f instead of 0x0
Rebooting...
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0xc (RTC_SW_CPU_RST),boot:0xb (SPI_FAST_FLASH_BOOT)
Saved PC:0x400267b8
0x400267b8: esp_restart_noos at /home/nileshkumar/development/gw-mesh/esp-idf/components/esp32s2/system_api_esp32s2.c:109 (discriminator 1)