Riscv ULP hangs on ulp_riscv_config_and_run in ESP32S3 (IDFGH-7719)

[Belal-Elshinnawey]

Environment

• Development Kit: Standalone ESP32-S3 with 2MB flash.
• IDF version : v5.0-dev-3654-gc2ccc383da
• Build System: idf.py
• Compiler version: xtensa-esp32s3-elf-gcc (crosstool-NG esp-2022r1-RC1) 11.2.0
• Operating System: Windows
• (Windows only) environment type: Plain Command Prompt
• Using an IDE?: No, IDE only for Dev, Everything else is manually by CMD
• Power Supply: Battery 3.7

Problem Description

I'm experimenting with the GPIO interrupt example for ESP32S3 ulp riscv.
Using the same GPIO 0, the problem exists in both RTC IO and regular GPIO.
What I am trying to do is have the ESP go to deepsleep and only wakeup the ULP from interrupt. The ULP can decide if it wants to wakeup The main processor or not.

The problem is If the ESP resets, from Power, It does not init the ULP or go to Deepsleep (Current is 20mA). However, If I trigger the interrupt that causes the ULP to wake up the ESP(press the button), the main processor resets but manages to get the ULP to start, and manages to inter deepsleep afterwords.

Expected Behavior

The ESP should be able to Init the RISCV processor and continue the program as normal when Power reset is triggered.

Actual Behavior

The ESP hangs and stops responding when ulp_riscv_config_and_run(&cfg) is called. and does not execute any codes after it. Unless if the interrupt is triggered, then it works normally.

Steps to reproduce

1. get the https://github.com/espressif/esp-idf/tree/master/examples/system/ulp_riscv/gpio_interrupt from the ESP repo
2. set target as ESP32S3, and build flash it.
3. wait for the ESP to start ULP and go to sleep.
4. the ESP will stop at ulp_riscv_config_and_run
5. pull the GPIO0 pin low and the ESP will restart and work normally.
6. if you reset the esp via power it will do the same again

// If possible, attach a picture of your setup/wiring here.

Code to reproduce this issue

    /* ESP Code*/
    #include <stdio.h>
    #include "esp_sleep.h"
    #include "soc/sens_reg.h"
    #include "driver/gpio.h"
    #include "driver/rtc_io.h"
    #include "ulp_riscv.h"
    #include "freertos/FreeRTOS.h"
    #include "freertos/task.h"
    #define WAKEUP_PIN 0
    extern const uint8_t ulp_main_bin_start[] asm("_binary_ulp_main_bin_start");
    extern const uint8_t ulp_main_bin_end[]   asm("_binary_ulp_main_bin_end");
    static void init_ulp_program(void);
    static void wakeup_gpio_init(void)
    {
            rtc_gpio_init(WAKEUP_PIN);
            rtc_gpio_set_direction(WAKEUP_PIN, RTC_GPIO_MODE_INPUT_ONLY);
            rtc_gpio_pullup_dis(WAKEUP_PIN);
            rtc_gpio_pulldown_dis(WAKEUP_PIN);
            rtc_gpio_wakeup_enable(WAKEUP_PIN, GPIO_INTR_LOW_LEVEL);
    }
    void app_main(void)
    {
            esp_sleep_wakeup_cause_t cause = esp_sleep_get_wakeup_cause();

            /* not a wakeup from ULP, load the firmware */
            if (cause != ESP_SLEEP_WAKEUP_ULP) {
                    printf("Not a ULP-RISC-V wakeup, initializing it! \n");
                    wakeup_gpio_init();
                    init_ulp_program();
            }
            if (cause == ESP_SLEEP_WAKEUP_ULP) {
                    printf("ULP-RISC-V woke up the main CPU! \n");
             }
            printf("Entering in deep sleep\n\n");
            esp_sleep_pd_config(ESP_PD_DOMAIN_RTC_PERIPH, ESP_PD_OPTION_ON);
            ESP_ERROR_CHECK( esp_sleep_enable_ulp_wakeup());
            esp_deep_sleep_start();
    }
    static void init_ulp_program(void)
    { 
            esp_err_t err = ulp_riscv_load_binary(ulp_main_bin_start, (ulp_main_bin_end - ulp_main_bin_start));
            ESP_ERROR_CHECK(err);
            /* Start the program */
            ulp_riscv_cfg_t cfg = {
                    .wakeup_source = ULP_RISCV_WAKEUP_SOURCE_GPIO,
            };
            err = ulp_riscv_config_and_run(&cfg);
            ESP_ERROR_CHECK(err);
    }

    /*ULP Riscv Code*/
    #include <stdio.h>
    #include <stdint.h>
    #include <stdbool.h>
    #include "ulp_riscv.h"
    #include "ulp_riscv_utils.h"
    #include "ulp_riscv_gpio.h"

    int main (void)
    {   
            ulp_riscv_wakeup_main_processor();
             ulp_riscv_delay_cycles(1000*1000 * ULP_RISCV_CYCLES_PER_US);
            ulp_riscv_gpio_wakeup_clear();
            return 0;
    }

Debug Logs When Power reset:

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x29 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3810,len:0x1708
load:0x403c9700,len:0xbe0
load:0x403cc700,len:0x2e60
entry 0x403c9904
I (25) boot: ESP-IDF v5.0-dev-3654-gc2ccc383da 2nd stage bootloader
I (25) boot: compile time 06:10:36
I (25) boot: chip revision: 0
I (28) boot.esp32s3: Boot SPI Speed : 80MHz
I (33) boot.esp32s3: SPI Mode : DIO
I (38) boot.esp32s3: SPI Flash Size : 2MB
I (42) boot: Enabling RNG early entropy source...
I (48) boot: Partition Table:
I (51) boot: ## Label Usage Type ST Offset Length
I (59) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (66) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (74) boot: 2 factory factory app 00 00 00010000 00100000
I (81) boot: End of partition table
I (85) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=08ea4h ( 36516) map
I (100) esp_image: segment 1: paddr=00018ecc vaddr=3fc91d60 size=02d04h ( 11524) load
I (104) esp_image: segment 2: paddr=0001bbd8 vaddr=40374000 size=04440h ( 17472) load
I (114) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=197a0h (104352) map
I (138) esp_image: segment 4: paddr=000397c8 vaddr=40378440 size=09914h ( 39188) load
I (147) esp_image: segment 5: paddr=000430e4 vaddr=50001ff0 size=00010h ( 16) load
I (147) esp_image: segment 6: paddr=000430fc vaddr=600fe000 size=00028h ( 40) load
I (158) boot: Loaded app from partition at offset 0x10000
I (159) boot: Disabling RNG early entropy source...
I (175) cpu_start: Pro cpu up.
I (175) cpu_start: Starting app cpu, entry point is 0x403752ec
0x403752ec: call_start_cpu1 at C:/Users/belal/esp/esp-idf/components/esp_system/port/cpu_start.c:147

I (0) cpu_stDr(1: ) e csp: un ._BV 2ACDE_AERRE iislegal er oit isttrt clr & en0 mitsk is
D (1x3f
V sACHIn_EFRRE cor2_1 acc4ss error intr8 lr & ena minsk is: 0x f

D (198) clk: RTC_SLOW_CLK calibration value: 3812006
V CACHE_ERR: illegal error intr clr & ena mask is: 0x3f
V CACHE_ERR: core 0 access error intr clr & ena mask is: 0x1f
I (207) cpu_start: Pro cpu start user code
I (210) cpu_start: cpu freq: 160000000 Hz
I (215) cpu_start: Application information:
I (220) cpu_start: Project name: lowPower_test
I (225) cpu_start: App version: 1
I (230) cpu_start: Compile time: Jun 30 2022 06:10:30
I (236) cpu_start: ELF file SHA256: 52c632f472b92ae3...
I (242) cpu_start: ESP-IDF: v5.0-dev-3654-gc2ccc383da
V (249) memory_layout: reserved range is 0x3c028e9c - 0x3c028ec4
D (255) memory_layout: Checking 6 reserved memory ranges:
D (260) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc91d54
D (266) memory_layout: Reserved memory range 0x3fc91d60 - 0x3fc954e0
D (273) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (279) memory_layout: Reserved memory range 0x40374000 - 0x40381d54
0x40374000: _WindowOverflow4 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742

D (286) memory_layout: Reserved memory range 0x600fe000 - 0x600fe028
D (292) memory_layout: Reserved memory range 0x600ffff0 - 0x60100000
D (299) memory_layout: Building list of available memory regions:
V (305) memory_layout: Examining memory region 0x40374000 - 0x40378000
0x40374000: _WindowOverflow4 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742

0x40378000: spi_flash_check_and_flush_cache at C:/Users/belal/esp/esp-idf/components/spi_flash/flash_mmap.c:489

V (311) memory_layout: Region 0x40374000 - 0x40378000 inside of reserved 0x40374000 - 0x40381d54
0x40374000: _WindowOverflow4 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742

0x40378000: spi_flash_check_and_flush_cache at C:/Users/belal/esp/esp-idf/components/spi_flash/flash_mmap.c:489

0x40374000: _WindowOverflow4 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742

V (320) memory_layout: Examining memory region 0x3fc88000 - 0x3fc90000
V (327) memory_layout: Region 0x3fc88000 - 0x3fc90000 inside of reserved 0x3fc84000 - 0x3fc91d54
V (336) memory_layout: Examining memory region 0x3fc90000 - 0x3fca0000
V (342) memory_layout: Start of region 0x3fc90000 - 0x3fca0000 overlaps reserved 0x3fc84000 - 0x3fc91d54
V (352) memory_layout: Region 0x3fc91d54 - 0x3fca0000 contains reserved 0x3fc91d60 - 0x3fc954e0
V (361) memory_layout: Examining memory region 0x3fc954e0 - 0x3fca0000
D (367) memory_layout: Available memory region 0x3fc954e0 - 0x3fca0000
V (374) memory_layout: Examining memory region 0x3fca0000 - 0x3fcb0000
D (380) memory_layout: Available memory region 0x3fca0000 - 0x3fcb0000
V (387) memory_layout: Examining memory region 0x3fcb0000 - 0x3fcc0000
D (393) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
V (400) memory_layout: Examining memory region 0x3fcc0000 - 0x3fcd0000
D (407) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
V (413) memory_layout: Examining memory region 0x3fcd0000 - 0x3fce0000
D (420) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
V (426) memory_layout: Examining memory region 0x3fce0000 - 0x3fcf0000
V (433) memory_layout: End of region 0x3fce0000 - 0x3fcf0000 overlaps reserved 0x3fceee34 - 0x3fcf0000
D (442) memory_layout: Available memory region 0x3fce0000 - 0x3fceee34
V (449) memory_layout: Examining memory region 0x3fcf0000 - 0x3fcf8000
D (456) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
V (462) memory_layout: Examining memory region 0x600fe000 - 0x60100000
V (469) memory_layout: Start of region 0x600fe000 - 0x60100000 overlaps reserved 0x600fe000 - 0x600fe028
V (478) memory_layout: End of region 0x600fe028 - 0x60100000 overlaps reserved 0x600ffff0 - 0x60100000
D (488) memory_layout: Available memory region 0x600fe028 - 0x600ffff0
I (494) heap_init: Initializing. RAM available for dynamic allocation:
D (502) heap_init: New heap initialised at 0x3fc954e0
I (507) heap_init: At 3FC954E0 len 0004AB20 (298 KiB): D/IRAM
I (513) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
D (520) heap_init: New heap initialised at 0x3fcf0000
I (525) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (531) heap_init: New heap initialised at 0x600fe028
I (536) heap_init: At 600FE028 len 00001FC8 (7 KiB): RTCRAM
V (543) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (549) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (557) intr_alloc: Connected src 39 to int 2 (cpu 0)
V (563) memspi: raw_chip_id: 1540EF

V (566) memspi: chip_id: EF4015

V (569) memspi: raw_chip_id: 1540EF

V (573) memspi: chip_id: EF4015

D (576) spi_flash: trying chip: issi
D (580) spi_flash: trying chip: gd
D (583) spi_flash: trying chip: mxic
D (587) spi_flash: trying chip: winbond
I (591) spi_flash: detected chip: winbond
I (596) spi_flash: flash io: dio
D (600) cpu_start: calling init function: 0x42007f4c
0x42007f4c: esp_ipc_init at C:/Users/belal/esp/esp-idf/components/esp_system/esp_ipc.c:109

D (605) cpu_start: calling init function: 0x42001dd0
0x42001dd0: esp_reset_reason_init at C:/Users/belal/esp/esp-idf/components/esp_system/port/soc/esp32s3/reset_reason.c:67

D (610) cpu_start: calling init function: 0x420010e0
0x420010e0: esp_ota_init_app_elf_sha256 at C:/Users/belal/esp/esp-idf/components/app_update/esp_app_desc.c:68

V (615) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (621) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC02
D (629) intr_alloc: Connected src 59 to int 3 (cpu 0)
I (634) sleep: Configure to isolate all GPIO pins in sleep state
I (641) sleep: Enable automatic switching of GPIO sleep configuration
V (660) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (660) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (663) intr_alloc: Connected src 79 to int 9 (cpu 0)
I (668) cpu_start: Starting scheduler on PRO CPU.
V (674) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (674) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x402
D (674) intr_alloc: Connected src 57 to int 12 (cpu 0)
V (674) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (684) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E
D (684) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (694) cpu_start: Starting scheduler on APP CPU.
V (694) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (704) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x402
D (714) intr_alloc: Connected src 58 to int 3 (cpu 1)
D (714) heap_init: New heap initialised at 0x3fce0000
V (724) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (734) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (734) intr_alloc: Connected src 52 to int 13 (cpu 0)
Not a ULP-RISC-V wakeup, initializing it!
//////////////////////////////////////////// Program should not stop here!/////////////////////////////////////////////////////////////

Debug Logs When GPIO is pulled low once to make the APP start normally:

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0x29 (SPI_FAST_FLASH_BOOT)
Saved PC:0x4200540f
0x4200540f: uart_ll_get_txfifo_len at C:/Users/belal/esp/esp-idf/components/hal/esp32s3/include/hal/uart_ll.h:321 (discriminator 1)
(inlined by) uart_tx_char at C:/Users/belal/esp/esp-idf/components/vfs/vfs_uart.c:156 (discriminator 1)

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3810,len:0x1708
load:0x403c9700,len:0xbe0
load:0x403cc700,len:0x2e60
entry 0x403c9904
I (75) boot: ESP-IDF v5.0-dev-3654-gc2ccc383da 2nd stage bootloader
I (76) boot: compile time 06:10:36
I (76) boot: chip revision: 0
I (79) boot.esp32s3: Boot SPI Speed : 80MHz
I (84) boot.esp32s3: SPI Mode : DIO
I (88) boot.esp32s3: SPI Flash Size : 2MB
W (93) boot.esp32s3: PRO CPU has been reset by WDT.
W (99) boot.esp32s3: APP CPU has been reset by WDT.
I (104) boot: Enabling RNG early entropy source...
I (110) boot: Partition Table:
I (113) boot: ## Label Usage Type ST Offset Length
I (121) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (128) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (136) boot: 2 factory factory app 00 00 00010000 00100000
I (143) boot: End of partition table
I (148) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=08ea4h ( 36516) map
I (163) esp_image: segment 1: paddr=00018ecc vaddr=3fc91d60 size=02d04h ( 11524) load
I (167) esp_image: segment 2: paddr=0001bbd8 vaddr=40374000 size=04440h ( 17472) load
I (177) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=197a0h (104352) map
I (200) esp_image: segment 4: paddr=000397c8 vaddr=40378440 size=09914h ( 39188) load
I (209) esp_image: segment 5: paddr=000430e4 vaddr=50001ff0 size=00010h ( 16) load
I (210) esp_image: segment 6: paddr=000430fc vaddr=600fe000 size=00028h ( 40) load
I (221) boot: Loaded app from partition at offset 0x10000
I (221) boot: Disabling RNG early entropy source...
I (238) cpu_start: Pro cpu up.
I (238) cpu_start: Starting app cpu, entry point is 0x403752ec
0x403752ec: call_start_cpu1 at C:/Users/belal/esp/esp-idf/components/esp_system/port/cpu_start.c:147

I (0) cpu_start: App cpu up.
V CACHE_ERR: illegal error intr clr & ena mask is: 0x3f
V CACHE_ERR: Dore 17 acck:ss e_Sror intr clir at ena mask 3s: 0x2f
m
V CACHE_ERR: illegal error intr clr & ena mask is: 0x3f
V CACHE_ERR: core 0 access error intr clr & ena mask is: 0x1f
I (263) cpu_start: Pro cpu start user code
I (267) cpu_start: cpu freq: 160000000 Hz
I (272) cpu_start: Application information:
I (277) cpu_start: Project name: lowPower_test
I (282) cpu_start: App version: 1
I (287) cpu_start: Compile time: Jun 30 2022 06:10:30
I (293) cpu_start: ELF file SHA256: 52c632f472b92ae3...
I (299) cpu_start: ESP-IDF: v5.0-dev-3654-gc2ccc383da
V (305) memory_layout: reserved range is 0x3c028e9c - 0x3c028ec4
D (311) memory_layout: Checking 6 reserved memory ranges:
D (317) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc91d54
D (323) memory_layout: Reserved memory range 0x3fc91d60 - 0x3fc954e0
D (329) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (336) memory_layout: Reserved memory range 0x40374000 - 0x40381d54
0x40374000: _WindowOverflow4 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742

D (342) memory_layout: Reserved memory range 0x600fe000 - 0x600fe028
D (349) memory_layout: Reserved memory range 0x600ffff0 - 0x60100000
D (355) memory_layout: Building list of available memory regions:
V (361) memory_layout: Examining memory region 0x40374000 - 0x40378000
0x40374000: _WindowOverflow4 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742

0x40378000: spi_flash_check_and_flush_cache at C:/Users/belal/esp/esp-idf/components/spi_flash/flash_mmap.c:489

V (368) memory_layout: Region 0x40374000 - 0x40378000 inside of reserved 0x40374000 - 0x40381d54
0x40374000: _WindowOverflow4 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742

0x40378000: spi_flash_check_and_flush_cache at C:/Users/belal/esp/esp-idf/components/spi_flash/flash_mmap.c:489

0x40374000: _WindowOverflow4 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1742

V (377) memory_layout: Examining memory region 0x3fc88000 - 0x3fc90000
V (383) memory_layout: Region 0x3fc88000 - 0x3fc90000 inside of reserved 0x3fc84000 - 0x3fc91d54
V (392) memory_layout: Examining memory region 0x3fc90000 - 0x3fca0000
V (399) memory_layout: Start of region 0x3fc90000 - 0x3fca0000 overlaps reserved 0x3fc84000 - 0x3fc91d54
V (408) memory_layout: Region 0x3fc91d54 - 0x3fca0000 contains reserved 0x3fc91d60 - 0x3fc954e0
V (417) memory_layout: Examining memory region 0x3fc954e0 - 0x3fca0000
D (424) memory_layout: Available memory region 0x3fc954e0 - 0x3fca0000
V (430) memory_layout: Examining memory region 0x3fca0000 - 0x3fcb0000
D (437) memory_layout: Available memory region 0x3fca0000 - 0x3fcb0000
V (444) memory_layout: Examining memory region 0x3fcb0000 - 0x3fcc0000
D (450) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
V (457) memory_layout: Examining memory region 0x3fcc0000 - 0x3fcd0000
D (463) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
V (470) memory_layout: Examining memory region 0x3fcd0000 - 0x3fce0000
D (477) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
V (483) memory_layout: Examining memory region 0x3fce0000 - 0x3fcf0000
V (490) memory_layout: End of region 0x3fce0000 - 0x3fcf0000 overlaps reserved 0x3fceee34 - 0x3fcf0000
D (499) memory_layout: Available memory region 0x3fce0000 - 0x3fceee34
V (506) memory_layout: Examining memory region 0x3fcf0000 - 0x3fcf8000
D (512) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
V (519) memory_layout: Examining memory region 0x600fe000 - 0x60100000
V (525) memory_layout: Start of region 0x600fe000 - 0x60100000 overlaps reserved 0x600fe000 - 0x600fe028
V (535) memory_layout: End of region 0x600fe028 - 0x60100000 overlaps reserved 0x600ffff0 - 0x60100000
D (544) memory_layout: Available memory region 0x600fe028 - 0x600ffff0
I (551) heap_init: Initializing. RAM available for dynamic allocation:
D (558) heap_init: New heap initialised at 0x3fc954e0
I (563) heap_init: At 3FC954E0 len 0004AB20 (298 KiB): D/IRAM
I (570) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
D (576) heap_init: New heap initialised at 0x3fcf0000
I (582) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (588) heap_init: New heap initialised at 0x600fe028
I (593) heap_init: At 600FE028 len 00001FC8 (7 KiB): RTCRAM
V (599) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (605) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (614) intr_alloc: Connected src 39 to int 2 (cpu 0)
V (619) memspi: raw_chip_id: 1540EF

V (622) memspi: chip_id: EF4015

V (626) memspi: raw_chip_id: 1540EF

V (630) memspi: chip_id: EF4015

D (633) spi_flash: trying chip: issi
D (637) spi_flash: trying chip: gd
D (640) spi_flash: trying chip: mxic
D (644) spi_flash: trying chip: winbond
I (648) spi_flash: detected chip: winbond
I (652) spi_flash: flash io: dio
D (656) cpu_start: calling init function: 0x42007f4c
0x42007f4c: esp_ipc_init at C:/Users/belal/esp/esp-idf/components/esp_system/esp_ipc.c:109

D (661) cpu_start: calling init function: 0x42001dd0
0x42001dd0: esp_reset_reason_init at C:/Users/belal/esp/esp-idf/components/esp_system/port/soc/esp32s3/reset_reason.c:67

D (666) cpu_start: calling init function: 0x420010e0
0x420010e0: esp_ota_init_app_elf_sha256 at C:/Users/belal/esp/esp-idf/components/app_update/esp_app_desc.c:68

V (671) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (678) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC02
D (686) intr_alloc: Connected src 59 to int 3 (cpu 0)
I (691) sleep: Configure to isolate all GPIO pins in sleep state
I (698) sleep: Enable automatic switching of GPIO sleep configuration
V (716) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (716) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (720) intr_alloc: Connected src 79 to int 9 (cpu 0)
I (725) cpu_start: Starting scheduler on PRO CPU.
V (730) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (730) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x402
D (730) intr_alloc: Connected src 57 to int 12 (cpu 0)
V (730) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (740) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E
D (740) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (750) cpu_start: Starting scheduler on APP CPU.
V (750) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (760) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x402
D (770) intr_alloc: Connected src 58 to int 3 (cpu 1)
D (770) heap_init: New heap initialised at 0x3fce0000
V (780) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (790) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (790) intr_alloc: Connected src 52 to int 13 (cpu 0)
Not a ULP-RISC-V wakeup, initializing it!
Entering in deep sleep <<==== Enters Deep sleep Normally, and power is in uA range after ULP is started.

[ESP-Marius]

Hi, @Belal-Elshinnawey

I haven't been able to reproduce it. Atleast with my S3 dev-kitC-1, the board always enters deep sleep like it should even on the first power on cycle.

Can you think of anything else you've changed, e.g. menuconfig options? If you just do a clean build from scratch using the example without any modifications does it still happen?

There shouldn't really be any places where the SW can get stuck inside ulp_riscv_config_and_run, as it is just setting some registers 🤔 . Are you able to add some more debug printing/check with a JTAG to help us narrow down where you actually get stuck?

[Belal-Elshinnawey]

I tried what you said, I tried with the same devboard that you have also, I get the same behavior.

[ESP-Marius]

How are you connecting to the board? Is it over the USB marked UART or the one marked USB?

[Belal-Elshinnawey]

UART, the USB interface doesn't work,
Also I have additional outputs on my my Devkit when I trigger the interrupt for the first time to get the example to work:

Backtrace:0x40376c37:0x3fc924100x40376aca:0x3fc92430 0x40378ae3:0x3fcf4630 0x42001f02:0x3fcf4650 0x4037b749:0x3fcf4670 0x4037cb65:0x3fcf4690
0x40376c37: systimer_ll_clear_alarm_int at C:/Users/belal/esp/esp-idf/components/hal/esp32s3/include/hal/systimer_ll.h:165
(inlined by) at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/port_systick.c:130

0x40376aca: _xt_lowint1 at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1117

0x40378ae3: xt_utils_wait_for_intr at C:/Users/belal/esp/esp-idf/components/xtensa/include/xt_utils.h:81
(inlined by) esp_cpu_wait_for_intr at C:/Users/belal/esp/esp-idf/components/esp_hw_support/cpu.c:100

0x42001f02: cpu_ll_waiti at C:/Users/belal/esp/esp-idf/components/esp_hw_support/include/hal/cpu_ll.h:111
(inlined by) esp_vApplicationIdleHook at C:/Users/belal/esp/esp-idf/components/esp_system/freertos_hooks.c:58

0x4037b749: prvIdleTask at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:3969 (discriminator 1)
0x4037cb65: vPortTaskWrapper at C:/Users/belal/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:141

/////Device reboots and starts working normally.////////

[ESP-Marius]

Hmm, still not able to reproduce this is any way 🤔

A few suggestions:

1. Can you try to use e.g. esp_rom_printf() to figure out exactly where in ulp_riscv_config_and_run it gets stuck? (Just add a few prints and see which is the first one that never gets output)
2. Does this still happen if you remove ulp_riscv_wakeup_main_processor() from the ULP-Riscv main.c?

[Belal-Elshinnawey]

So, it turns out that I somehow managed to brick multiple boards. the ulp is working as expected, I ordered few extra boards and with brand new esp. I don't know what I did to destroy the old ones, but what i know is it wasn't hanging in the ulp_riscv_config_and_run, it was hanging when the esp_deep_sleep_start is called. it would sleep until any condition is met, say the timer is reached, or if I'm using the interrupt example, when the pin is pressed, the esp would crash and restart a normal restart with a wakeup cause different then an ulp wakeup. new board, new esp fixed it, I hope I don't brick this one too.

Cheers!

[ESP-Marius]

@Belal-Elshinnawey Good to hear that it resolved itself somehow.

I'll close this issue for now then, but please feel free to re-open (or open a new one) if anything similar happens again.