ESP-S3 deep sleep not functional

[maskemaske]

Hi,

I am using this code on ESP32-S3-DevKitC-1
https://pastebin.com/4WyxerTX
Note Line 54 esp_sleep_config_gpio_isolate() removing this does not make a difference.

I cannot get deep sleep to work. The device never enters deep sleep. Instead the WDT kicks after 5 seconds. If WDT for IDLE is disabled, the device hangs indefinitely. The WDT stacktrace reports the device is stuck at

Code: Select all

0x40378bce: esp_deep_sleep_start at /home/username/esp/esp-idf/components/esp_hw_support/sleep_modes.c:496

I am using

Code: Select all

idf.py --version
ESP-IDF v4.4-dev-3235-g3e370c4296

Looking up Line 496 on https://github.com/espressif/esp-idf/bl ... ep_modes.c that line appears to be empty. Probably due to the #ifdef mess! Likely candidates are
rtc_clk_cpu_freq_set_config and call_rtc_sleep_start calls

I have tested to change the CPU frequency to 80/160/240MHz. I have tested on a devkitC-1 and on custom board with and without external RTC. I have tested to use esp_sleep_enable_ext1_wakeup instead of timer-wakeup. Nothing changes the fact that esp_deep_sleep_start() never actually enters deep sleep.

Am I doing it wrong?

Edit:
An interesting observation; after calling esp_deep_sleep_start(), and waiting 5 seconds, the watchdog triggers (evident by log output), but it fails to reset the device. Instead, the watchdog timeout keeps triggering every 5 seconds. This is not how a WDT is supposed to work, is it?

[maskemaske]

This is still an issue. To reproduce, all you need to do is copy the deep-sleep example, run "idf.py set-target esp32-s3" and "idf.py menuconfig" to configure/disable touch and GPIO wakeup depending on your board, and "idf.py flash monitor" it.

Below is output from unmodified deep sleep example, using USB-JTAG.

SP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40048836
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x17d4
load:0x403b6000,len:0x8d8
load:0x403ba000,len:0x3000
entry 0x403b61c0
I (24) boot: ESP-IDF v4.4-dev-3235-g3e370c4296 2nd stage bootloader
I (25) boot: compile time 08:42:06
I (25) boot: chip revision: 0
I (28) boot.esp32s3: Boot SPI Speed : 80MHz
I (33) boot.esp32s3: SPI Mode : DIO
I (37) boot.esp32s3: SPI Flash Size : 2MB
I (42) boot: Enabling RNG early entropy source...
W (48) bootloader_random: RNG for ESP32-S3 not currently supported
I (54) boot: Partition Table:
I (58) boot: ## Label Usage Type ST Offset Length
I (65) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (73) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (80) boot: 2 factory factory app 00 00 00010000 00100000
I (88) boot: End of partition table
I (92) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=07600h ( 30208) map
I (106) esp_image: segment 1: paddr=00017628 vaddr=3fc91560 size=02634h ( 9780) load
I (111) esp_image: segment 2: paddr=00019c64 vaddr=40374000 size=063b4h ( 25524) load
I (123) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=165c0h ( 91584) map
I (142) esp_image: segment 4: paddr=000365e8 vaddr=4037a3b4 size=071a8h ( 29096) load
I (149) esp_image: segment 5: paddr=0003d798 vaddr=50000000 size=00018h ( 24) load
I (149) esp_image: segment 6: paddr=0003d7b8 vaddr=600fe000 size=00008h ( 8) load
I (162) boot: Loaded app from partition at offset 0x10000
I (162) boot: Disabling RNG early entropy source...
W (168) bootloader_random: RNG for ESP32-S3 not currently supported
I (186) cpu_start: Pro cpu up.
I (186) cpu_start: Starting app cpu, entry point is 0x40375164
0x40375164: call_start_cpu1 at /home/markus/esp/esp-idf/components/esp_system/port/cpu_start.c:155

I (0) cpu_start: App cpu up.
I (250) cpu_start: Pro cpu start user code
I (250) cpu_start: cpu freq: 160000000
I (251) cpu_start: Application information:
I (253) cpu_start: Project name: deep_sleep
I (258) cpu_start: App version: 1
I (263) cpu_start: Compile time: May 23 2022 08:42:02
I (269) cpu_start: ELF file SHA256: 322483d52b7b76b1...
I (275) cpu_start: ESP-IDF: v4.4-dev-3235-g3e370c4296
I (281) heap_init: Initializing. RAM available for dynamic allocation:
I (289) heap_init: At 3FC94578 len 0004BA88 (302 KiB): D/IRAM
I (295) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
I (302) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
W (317) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (0) cpu_start: Starting scheduler on APP CPU.
E (6341) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (6341) task_wdt: - IDLE (CPU 0)
E (6341) task_wdt: Tasks currently running:
E (6341) task_wdt: CPU 0: main
E (6341) task_wdt: CPU 1: IDLE
E (6341) task_wdt: Print CPU 0 (current core) backtrace


Backtrace:0x42006766:0x3FC920F00x4037677A:0x3FC92110 0x40378BC2:0x3FCF4160 0x42004C63:0x3FCF4180 0x420163F1:0x3FCF41B0 0x4037CACD:0x3FCF41D0
0x42006766: task_wdt_isr at /home/markus/esp/esp-idf/components/esp_system/task_wdt.c:191 (discriminator 3)

0x4037677a: _xt_lowint1 at /home/markus/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1111

0x40378bc2: esp_deep_sleep_start at /home/markus/esp/esp-idf/components/esp_hw_support/sleep_modes.c:496

0x42004c63: app_main at /home/markus/esp/deep_sleep/build/../main/deep_sleep_example_main.c:178 (discriminator 15)

0x420163f1: main_task at /home/markus/esp/esp-idf/components/freertos/port/port_common.c:136 (discriminator 2)

0x4037cacd: vPortTaskWrapper at /home/markus/esp/esp-idf/components/freertos/port/xtensa/port.c:159


E (6341) task_wdt: Print CPU 1 backtrace


Backtrace:0x40377C79:0x3FC926F00x4037677A:0x3FC92710 0x400559DD:0x3FCF4FD0 |<-CORRUPTED
0x40377c79: esp_crosscore_isr at /home/markus/esp/esp-idf/components/esp_system/crosscore_int.c:92

0x4037677a: _xt_lowint1 at /home/markus/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1111


E (11341) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (11341) task_wdt: - IDLE (CPU 0)
E (11341) task_wdt: Tasks currently running:
E (11341) task_wdt: CPU 0: main
E (11341) task_wdt: CPU 1: IDLE
E (11341) task_wdt: Print CPU 0 (current core) backtrace


Backtrace:0x42006766:0x3FC920F00x4037677A:0x3FC92110 0x40378BC2:0x3FCF4160 0x42004C63:0x3FCF4180 0x420163F1:0x3FCF41B0 0x4037CACD:0x3FCF41D0
0x42006766: task_wdt_isr at /home/markus/esp/esp-idf/components/esp_system/task_wdt.c:191 (discriminator 3)

0x4037677a: _xt_lowint1 at /home/markus/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1111

0x40378bc2: esp_deep_sleep_start at /home/markus/esp/esp-idf/components/esp_hw_support/sleep_modes.c:496

0x42004c63: app_main at /home/markus/esp/deep_sleep/build/../main/deep_sleep_example_main.c:178 (discriminator 15)

0x420163f1: main_task at /home/markus/esp/esp-idf/components/freertos/port/port_common.c:136 (discriminator 2)

0x4037cacd: vPortTaskWrapper at /home/markus/esp/esp-idf/components/freertos/port/xtensa/port.c:159


E (11341) task_wdt: Print CPU 1 backtrace


Backtrace:0x40377C79:0x3FC926F00x4037677A:0x3FC92710 0x400559DD:0x3FCF4FD0 |<-CORRUPTED
0x40377c79: esp_crosscore_isr at /home/markus/esp/esp-idf/components/esp_system/crosscore_int.c:92

0x4037677a: _xt_lowint1 at /home/markus/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1111



Done

[maskemaske]

Debug output with loglevel=verbose:

--- idf_monitor on /dev/ttyACM0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
I (24) boot: ESP-IDF v4.4-dev-3235-g3e370c4296 2nd stage Fi data ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40048839
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x17d4
load:0x403b6000,len:0x8bc
load:0x403ba000,len:0x2fb0
entry 0x403b61b8
I (24) boot: ESP-IDF v4.4-dev-3235-g3e370c4296 2nd stage bootloader
I (25) boot: compile time 10:03:30
I (25) boot: chip revision: 0
I (28) boot.esp32s3: Boot SPI Speed : 80MHz
I (33) boot.esp32s3: SPI Mode : DIO
I (37) boot.esp32s3: SPI Flash Size : 2MB
I (42) boot: Enabling RNG early entropy source...
W (48) bootloader_random: RNG for ESP32-S3 not currently supported
I (54) boot: Partition Table:
I (58) boot: ## Label Usage Type ST Offset Length
I (65) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (73) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (80) boot: 2 factory factory app 00 00 00010000 00100000
I (88) boot: End of partition table
I (92) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=07c34h ( 31796) map
I (106) esp_image: segment 1: paddr=00017c5c vaddr=3fc92240 size=027ach ( 10156) load
I (111) esp_image: segment 2: paddr=0001a410 vaddr=40374000 size=05c08h ( 23560) load
I (122) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=15db0h ( 89520) map
I (142) esp_image: segment 4: paddr=00035dd8 vaddr=40379c08 size=08634h ( 34356) load
I (150) esp_image: segment 5: paddr=0003e414 vaddr=50000000 size=00018h ( 24) load
I (150) esp_image: segment 6: paddr=0003e434 vaddr=600fe000 size=00008h ( 8) load
I (162) boot: Loaded app from partition at offset 0x10000
I (162) boot: Disabling RNG early entropy source...
W (168) bootloader_random: RNG for ESP32-S3 not currently supported
I (175) cpu_start: Pro cpu up.
I (178) cpu_start: Starting app cpu, entry point is 0x403751b8
0x403751b8: call_start_cpu1 at /home/username/esp/esp-idf/components/esp_system/port/cpu_start.c:155

I (0) cpu_start: App cpu up.
D (185) clk: waiting for 32k oscillator to start up
D (248) clk: RTC_SLOW_CLK calibration value: 16002586
I (249) cpu_start: Pro cpu start user code
I (249) cpu_start: cpu freq: 160000000
I (249) cpu_start: Application information:
I (249) cpu_start: Project name: deep_sleep
I (249) cpu_start: App version: 1
I (250) cpu_start: Compile time: May 23 2022 10:03:27
I (250) cpu_start: ELF file SHA256: b0dcad542c18212a...
I (250) cpu_start: ESP-IDF: v4.4-dev-3235-g3e370c4296
V (251) memory_layout: reserved range is 0x3c027c34 - 0x3c027c54
D (251) memory_layout: Checking 5 reserved memory ranges:
D (251) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9223c
D (251) memory_layout: Reserved memory range 0x3fc92240 - 0x3fc95430
D (252) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (252) memory_layout: Reserved memory range 0x40374000 - 0x4038223c
0x40374000: _WindowOverflow4 at /home/username/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1736

D (252) memory_layout: Reserved memory range 0x600ffff0 - 0x60100000
D (253) memory_layout: Building list of available memory regions:
V (253) memory_layout: Examining memory region 0x40374000 - 0x40378000
0x40374000: _WindowOverflow4 at /home/username/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1736

0x40378000: esp_flash_init_main at /home/username/esp/esp-idf/components/spi_flash/esp_flash_api.c:340

V (253) memory_layout: Region 0x40374000 - 0x40378000 inside of reserved 0x40374000 - 0x4038223c
0x40374000: _WindowOverflow4 at /home/username/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1736

0x40378000: esp_flash_init_main at /home/username/esp/esp-idf/components/spi_flash/esp_flash_api.c:340

0x40374000: _WindowOverflow4 at /home/username/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1736

V (254) memory_layout: Examining memory region 0x3fc88000 - 0x3fc90000
V (254) memory_layout: Region 0x3fc88000 - 0x3fc90000 inside of reserved 0x3fc84000 - 0x3fc9223c
V (254) memory_layout: Examining memory region 0x3fc90000 - 0x3fca0000
V (255) memory_layout: Start of region 0x3fc90000 - 0x3fca0000 overlaps reserved 0x3fc84000 - 0x3fc9223c
V (255) memory_layout: Region 0x3fc9223c - 0x3fca0000 contains reserved 0x3fc92240 - 0x3fc95430
V (255) memory_layout: Examining memory region 0x3fc95430 - 0x3fca0000
D (256) memory_layout: Available memory region 0x3fc95430 - 0x3fca0000
V (256) memory_layout: Examining memory region 0x3fca0000 - 0x3fcb0000
D (257) memory_layout: Available memory region 0x3fca0000 - 0x3fcb0000
V (257) memory_layout: Examining memory region 0x3fcb0000 - 0x3fcc0000
D (257) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
V (258) memory_layout: Examining memory region 0x3fcc0000 - 0x3fcd0000
D (258) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
V (258) memory_layout: Examining memory region 0x3fcd0000 - 0x3fce0000
D (258) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
V (259) memory_layout: Examining memory region 0x3fce0000 - 0x3fcf0000
V (259) memory_layout: End of region 0x3fce0000 - 0x3fcf0000 overlaps reserved 0x3fceee34 - 0x3fcf0000
D (260) memory_layout: Available memory region 0x3fce0000 - 0x3fceee34
V (260) memory_layout: Examining memory region 0x3fcf0000 - 0x3fcf8000
D (260) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
I (261) heap_init: Initializing. RAM available for dynamic allocation:
D (261) heap_init: New heap initialised at 0x3fc95430
I (261) heap_init: At 3FC95430 len 0004ABD0 (298 KiB): D/IRAM
I (261) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
D (262) heap_init: New heap initialised at 0x3fcf0000
I (262) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (263) FLASH_HAL: extra_dummy: 0
V (263) memspi: raw_chip_id: 174020

V (263) memspi: chip_id: 204017

V (264) memspi: raw_chip_id: 174020

V (264) memspi: chip_id: 204017

D (264) spi_flash: trying chip: issi
D (264) spi_flash: trying chip: gd
D (264) spi_flash: trying chip: mxic
D (264) spi_flash: trying chip: winbond
D (265) spi_flash: trying chip: boya
D (265) spi_flash: trying chip: mxic (opi)
D (265) spi_flash: trying chip: generic
I (265) spi_flash: detected chip: generic
I (265) spi_flash: flash io: dio
W (265) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
D (266) cpu_start: calling init function: 0x42004c04
0x42004c04: esp_ipc_init at /home/username/esp/esp-idf/components/esp_ipc/src/esp_ipc.c:105

D (266) cpu_start: calling init function: 0x42000f4c
0x42000f4c: __esp_stack_guard_setup at /home/username/esp/esp-idf/components/esp_system/stack_check.c:28

D (266) stack_chk: Intialize random stack guard
D (266) cpu_start: calling init function: 0x42000e30
0x42000e30: esp_ota_init_app_elf_sha256 at /home/username/esp/esp-idf/components/app_update/esp_app_desc.c:68

V (267) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (267) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC02
D (267) intr_alloc: Connected src 59 to int 2 (cpu 0)
V (268) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (268) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (268) intr_alloc: Connected src 79 to int 3 (cpu 0)
I (268) cpu_start: Starting scheduler on PRO CPU.
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x402
D (269) intr_alloc: Connected src 57 to int 9 (cpu 0)
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E
D (269) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (269) cpu_start: Starting scheduler on APP CPU.
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x402
D (269) intr_alloc: Connected src 58 to int 3 (cpu 1)
D (269) heap_init: New heap initialised at 0x3fce0000
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (269) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (269) intr_alloc: Connected src 52 to int 12 (cpu 0)
I (269) MAIN: Not a deep sleep reset

I (1269) MAIN: Enabling timer wakeup, 20s

I (1269) MAIN: Entering deep sleep

D (1269) sleep: RTC_PERIPH: AUTO(OFF)
D (1269) sleep: RTC_SLOW_MEM: ON
D (1269) sleep: RTC_FAST_MEM: ON
E (6259) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (6259) task_wdt: - IDLE (CPU 0)
E (6259) task_wdt: Tasks currently running:
E (6259) task_wdt: CPU 0: main
E (6259) task_wdt: CPU 1: IDLE
E (6259) task_wdt: Print CPU 0 (current core) backtrace


Backtrace:0x42005D6A:0x3FC92D800x4037689A:0x3FC92DA0 0x4037915A:0x3FCF6F30 0x420047BF:0x3FCF6F50 0x42015BE1:0x3FCF6F80 0x4037CDC5:0x3FCF6FA0
0x42005d6a: task_wdt_isr at /home/username/esp/esp-idf/components/esp_system/task_wdt.c:191 (discriminator 3)

0x4037689a: _xt_lowint1 at /home/username/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1111

0x4037915a: esp_deep_sleep_start at /home/username/esp/esp-idf/components/esp_hw_support/sleep_modes.c:496

0x420047bf: app_main at /home/username/esp/deep_sleep/build/../main/deep_sleep_example_main.c:178 (discriminator 15)

0x42015be1: main_task at /home/username/esp/esp-idf/components/freertos/port/port_common.c:136 (discriminator 2)

0x4037cdc5: vPortTaskWrapper at /home/username/esp/esp-idf/components/freertos/port/xtensa/port.c:159


E (6259) task_wdt: Print CPU 1 backtrace


Backtrace:0x403781F1:0x3FC933800x4037689A:0x3FC933A0 0x400559DD:0x3FC95F70 |<-CORRUPTED
0x403781f1: esp_crosscore_isr at /home/username/esp/esp-idf/components/esp_system/crosscore_int.c:92

0x4037689a: _xt_lowint1 at /home/username/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1111



Done

[ESP_Sprite]

Do you also get this behaviour using UART output instead of USB-JTAG-serial?

[maskemaske]

Hi,
the issue is resolved by updating to latest IDF.