I have a usb power device that only wakes every x minutes, sends data and goes back to sleep. MY device is a esp32 s3 rev 0.01, and i have 16MB of psram. Recently i started to see a weird issue happening after a triggered restart or after crashes, the device would hang and never shutdown again.
I managed to reproduce the scenario with a very simple code, also tested this on other esp boards , not only my own hardware:
Code: Select all
#include <stdio.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_system.h"
void app_main(void)
{
printf("=== TEST: Timing issue check ===\n");
fflush(stdout);
// Additional delay before restart
vTaskDelay(1000 / portTICK_PERIOD_MS);
esp_system_abort("Manual restart");
}
Enabling bootloader logs at verbose level i see that after a few restarts the code hangs at :
Code: Select all
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40379144
--- 0x40379144: esp_restart_noos at /Users/paulo/esp/v5.5.1/esp-idf/components/esp_system/port/soc/esp32s3/system_internal.c:162
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce2820,len:0x2190
load:0x403c8700,len:0xedc
load:0x403cb700,len:0x3440
entry 0x403c8974
I (24) boot: ESP-IDF v5.5.1-dirty 2nd stage bootloader
I (24) boot: compile time Sep 30 2025 17:56:20
I (24) boot: Multicore bootloader
D (25) bootloader_flash: non-XMC chip detected by SFDP Read (C8), skip.
D (31) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (37) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (44) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (50) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (57) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (63) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (69) boot: chip revision: v0.2
I (72) boot: efuse block revision: v1.3
D (76) boot.esp32s3: magic e9
D (79) boot.esp32s3: segments 03
D (82) boot.esp32s3: spi_mode 02
D (85) boot.esp32s3: spi_speed 0f
D (88) boot.esp32s3: spi_size 03
I (91) boot.esp32s3: Boot SPI Speed : 80MHz
I (94) boot.esp32s3: SPI Mode : DIO
I (98) boot.esp32s3: SPI Flash Size : 8MB
D (102) boot: Enabling RTCWDT(9000 ms)
I (105) boot: Enabling RNG early entropy source...
D (110) bootloader_flash: rodata starts from paddr=0x00008000, size=0xc00, will be mapped to vaddr=0x3c000000
V (119) bootloader_flash: after mapping, starting from paddr=0x00000000 and vaddr=0x3c000000, 0x10000 bytes are mapped
D (130) boot: mapped partition table 0x8000 at 0x3c008000
D (135) flash_parts: partition table verified, 4 entries
I (140) boot: Partition Table:
I (143) boot: ## Label Usage Type ST Offset Length
D (149) boot: load partition table entry 0x3c008000
D (154) boot: type=1 subtype=2
I (157) boot: 0 nvs WiFi data 01 02 00009000 00006000
D (163) boot: load partition table entry 0x3c008020
D (168) boot: type=1 subtype=1
I (171) boot: 1 phy_init RF data 01 01 0000f000 00001000
D (177) boot: load partition table entry 0x3c008040
D (182) boot: type=0 subtype=0
I (185) boot: 2 factory factory app 00 00 00010000 00100000
I (191) boot: End of partition table
D (194) boot: Trying partition index -1 offs 0x10000 size 0x100000
D (200) esp_image: reading image header @ 0x10000
D (205) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (211) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (218) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (224) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (231) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (237) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (244) esp_image: image header: 0xe9 0x06 0x02 0x01 403752ec
V (249) esp_image: loading segment header 0 at offset 0x10018
D (255) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (261) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
V (268) esp_image: segment data length 0x7e94 data starts 0x10020
V (274) esp_image: MMU page size 0x10000
V (277) esp_image: segment 0 map_segment 1 segment_data_offs 0x10020 load_addr 0x3c020020
I (285) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=07e94h ( 32404) map
D (293) esp_image: free data page_count 0x00000200
D (297) bootloader_flash: rodata starts from paddr=0x00010020, size=0x7e94, will be mapped to vaddr=0x3c000000
V (307) bootloader_flash: after mapping, starting from paddr=0x00010000 and vaddr=0x3c000000, 0x10000 bytes are mapped
V (323) esp_image: loading segment header 1 at offset 0x17eb4
D (323) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (329) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
V (336) esp_image: segment data length 0x28b8 data starts 0x17ebc
V (342) esp_image: MMU page size 0x10000
V (345) esp_image: segment 1 map_segment 0 segment_data_offs 0x17ebc load_addr 0x3fc92000
I (353) esp_image: segment 1: paddr=00017ebc vaddr=3fc92000 size=028b8h ( 10424) load
D (361) esp_image: free data page_count 0x00000200
D (365) bootloader_flash: rodata starts from paddr=0x00017ebc, size=0x28b8, will be mapped to vaddr=0x3c000000
V (375) bootloader_flash: after mapping, starting from paddr=0x00010000 and vaddr=0x3c000000, 0x10000 bytes are mapped
V (388) esp_image: loading segment header 2 at offset 0x1a774
D (391) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (397) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
V (404) esp_image: segment data length 0x589c data starts 0x1a77c
V (410) esp_image: MMU page size 0x10000
V (413) esp_image: segment 2 map_segment 0 segment_data_offs 0x1a77c load_addr 0x40374000
--- 0x40374000: _WindowOverflow4 at /Users/paulo/esp/v5.5.1/esp-idf/components/xtensa/xtensa_vectors.S:2027
I (421) esp_image: segment 2: paddr=0001a77c vaddr=40374000 size=0589ch ( 22684) load
D (429) esp_image: free data page_count 0x00000200
D (433) bootloader_flash: rodata starts from paddr=0x0001a77c, size=0x589c, will be mapped to vaddr=0x3c000000
V (443) bootloader_flash: after mapping, starting from paddr=0x00010000 and vaddr=0x3c000000, 0x20000 bytes are mapped
V (458) esp_image: loading segment header 3 at offset 0x20018
D (459) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
D (465) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
V (472) esp_image: segment data length 0x13908 data starts 0x20020
V (478) esp_image: MMU page size 0x10000
V (481) esp_image: segment 3 map_segment 1 segment_data_offs 0x20020 load_addr 0x42000020
--- 0x42000020: _stext at ??:?
I (489) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=13908h ( 80136) map
D (497) esp_image: free data page_count 0x00000200
D (501) bootloader_flash: rodata starts from paddr=0x00020020, size=0x13908, will be mapped to vaddr=0x3c000000
V (511) bootloader_flash: after mapping, starting from paddr=0x00020000 and vaddr=0x3c000000, 0x20000 bytes are mapped
V (536) esp_image: loading segment header 4 at offset 0x33928
D (536) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (536) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
V (543) esp_image: segment data length 0x8664 data starts 0x33930
V (549) esp_image: MMU page size 0x10000
V (552) esp_image: segment 4 map_segment 0 segment_data_offs 0x33930 load_addr 0x4037989c
--- 0x4037989c: xQueueSemaphoreTake at /Users/paulo/esp/v5.5.1/esp-idf/components/freertos/FreeRTOS-Kernel/queue.c:1782
I (560) esp_image: segment 4: paddr=00033930 vaddr=4037989c size=08664h ( 34404) load
D (568) esp_image: free data page_count 0x00000200
D (572) bootloader_flash: rodata starts from paddr=0x00033930, size=0x8664, will be mapped to vaddr=0x3c000000
V (582) bootloader_flash: after mapping, starting from paddr=0x00030000 and vaddr=0x3c000000, 0x10000 bytes are mapped
V (600) esp_image: loading segment header 5 at offset 0x3bf94
D (600) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (605) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
V (611) esp_image: segment data length 0x20 data starts 0x3bf9c
V (617) esp_image: MMU page size 0x10000
V (620) esp_image: segment 5 map_segment 0 segment_data_offs 0x3bf9c load_addr 0x50000000
I (628) esp_image: segment 5: paddr=0003bf9c vaddr=50000000 size=00020h ( 32) load
D (636) esp_image: free data page_count 0x00000200
D (640) bootloader_flash: rodata starts from paddr=0x0003bf9c, size=0x20, will be mapped to vaddr=0x3c000000
V (650) bootloader_flash: after mapping, starting from paddr=0x00030000 and vaddr=0x3c000000, 0x10000 bytes are mapped
V (660) esp_image: image start 0x00010000 end of last section 0x0003bfbc
D (667) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (673) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (680) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (686) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (693) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (699) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (706) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (712) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (719) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (725) boot: Calculated hash: f6b4307915b832fb2c09a7ec1bbe7212f197781df159925cfcda1673771f1d45
I (739) boot: Loaded app from partition at offset 0x10000
I (739) boot: Disabling RNG early entropy source...
D (743) boot: Mapping segment 0 as DROM
D (747) boot: Mapping segment 3 as IROM
D (751) boot: calling set_cache_and_start_app
D (755) boot: configure drom and irom and start
V (759) boot: rodata starts from paddr=0x00010020, vaddr=0x3c020020, size=0x7e94
V (766) boot: after mapping rodata, starting from paddr=0x00010000 and vaddr=0x3c020000, 0x10000 bytes are mapped
V (776) boot: mapped one page of the rodata, from paddr=0x00010000 and vaddr=0x3dff0000, 0x10000 bytes are mapped
V (786) boot: text starts from paddr=0x00020020, vaddr=0x42000020, size=0x13908
--- 0x42000020: _stext at ??:?
V (793) boot: after mapping text, starting from paddr=0x00020000 and vaddr=0x42000000, 0x20000 bytes are mapped
D (803) boot: start: 0x403752ec
--- 0x403752ec: call_start_cpu0 at /Users/paulo/esp/v5.5.1/esp-idf/components/esp_system/port/cpu_start.c:897I tried lowering flash frequency to 40, tried single code mode, boards with different psrams, but this happens 100% of the times, sometimes after 1 or 2 restarts, other times after 50 but it always happens, even using other boards and using this very simple code.
I would be really thankful if anyone has an idea that would point me into the correct direction.