Watchdog triggered after light sleep wake up

[dacitt]

Hi all,

in my esp32 freertos project I put the chip in light sleep, during witch ULP is active and check if a ADC value is over certain treshold.
Wake up works well, but if sleep last more than 2-3 minutes nothing happens and watchdog is triggered on esp_timer (no problem if sleep is less than 2 minutes).

Actually I have set in my project 2 task called by esp_timer callback, following instruction of espressif guide and they works well but after wake up from relative long light sleep they don't work anymore until watchdog action.

Log:
Task watchdog got triggered. The following tasks did not reset the watchdog in time:
- IDLE (CPU 0)
Tasks currently running:
CPU 0: esp_timer

Any suggestions? Are esp_timers incompatible with ULP adc/light sleep?

Thanks!

[ESP_igrr]

Hi dacitt, you might have run into a bug of some sort. Can you share your project (e.g. via a PM) so that we can reproduce the issue on our end?

[dacitt]

I will provide complete code soon.
Just a question to be sure: is it normal that esp_timer callback tasks are running also during light_sleep mode?
If i put a esp_logi inside the function task I can see log during sleep.

For example, one task is initialized in this way:

Code: Select all

 esp_timer_create_args_t x_args =
  {
    .callback = ACInputTask,        //!< Function to call when timer expires
    .arg = NULL,                      //!< Argument to pass to the callback
    .dispatch_method = ESP_TIMER_TASK,   //!< Call the callback from task or from ISR
    .name = "ACInputTim",
  };
  esp_timer_create(&x_args, &x_ACInput_Timer_Hdl);
  
  esp_timer_start_periodic(x_ACInput_Timer_Hdl, 250);

They work well in normal condition (no sleep).

Thanks

[ESP_igrr]

If i put a esp_logi inside the function task I can see log during sleep.

No, this most definitely should not be happening. If you see the logs being printed, this means that the chip is not in light sleep. All peripherals are clock gated in light sleep, so no UART output can be produced in this state.

I think the issue might be that if the timer period is 250 microseconds, but you insert a log message into the handler, so the handler will take more than 250 microseconds to run. Therefore it will be constantly executing (next timeout will trigger while the callback is still running). This will prevent lower priority task (such as the one where app_main is running) from running and entering light sleep. Try replacing log output with something which takes less than 250 microseconds (e.g. toggling a GPIO) or increase the timer period when doing this test, to give lower priority tasks a chance to run.

[dacitt]

Yes you are right, this task is continuously executed and main app is never called -> no call to light sleep.
Are esp timer freezed during light sleep? This short period of timer could be responsible of the trigger of watchdog after sleep?

Thanks

[ESP_igrr]

Timer callbacks are not executed during light sleep (no code is executed, because CPUs are clock gated). After wakeup, pending timers (which would have triggered during sleep) will run. However periodic timers will run at most once, and then will keep running with their expected period.

[nvtby_espf]

I confirm the problem with light sleep for ESP32-S2 for very similar example. It looks like watchdog of timer group 1 has very short timeout, like 600 for first stage (interrupt) and 1200 for second (system reset). I tried to reset stage 0 timeout to default 26,000,000 but what suprized me, that after leaving light sleep these timeouts appear reset to named values. I use low level program (direct manipulation with registers, so this behaviour really stalls me. What is the reason? RTOS? Or ROM firmware?
Similar deep sleep example works just fine.

Log of failure (ULP timer=250) follows

Code: Select all

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x4
load:0x3ffe6104,len:0x1308
load:0x4004c000,len:0x1580
load:0x40050000,len:0x1fe8
entry 0x4004c2e0

MCU reset 0x01
Edge count:          0
Ready to sleep

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x8 (TG1WDT_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x400270d8
0x400270d8: _xt_panic at C:/Users/nvaranki/esp/esp-idf/components/esp_system/port/panic_handler_asm.S:28

SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x4
load:0x3ffe6104,len:0x1308
load:0x4004c000,len:0x1580
load:0x40050000,len:0x1fe8
entry 0x4004c2e0
W (48) boot.esp32s2: PRO CPU has been reset by WDT.
W (48) boot.esp32s2: WDT reset info: PRO CPU PC=0x4004c613

ULP FSM wakeup on system reset
Edge count:        512     Wake count:   1
Cancelling FSM program...
Abnormal exit Xtensa program

Done

Log of lucky test (ULP timer=50) follows; disregard UART ruptures. That is what expected for timeout=250 too, but with more delay in between wake-ups.

Code: Select all

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x4
load:0x3ffe6104,len:0x1308
load:0x4004c000,len:0x1580
load:0x40050000,len:0x1fe8
entry 0x4004c2e0

MCU reset 0x01
Edge count:          0
Ready to sleep


Unexpected wakeup cause 00000000
Edge count:        257     Wake count:   1
Ready to sleep

�H��A�FSM wakeup from sleep
Edge count:        513     Wake count:   2
Ready to sleep

H��A�FSM wakeup from sleep
Edge count:        769     Wake count:   3
Ready to sleep

�H��A�FSM wakeup from sleep
Edge count:       1025     Wake count:   4
Ready to sleep

�H��A�FSM wakeup from sleep
Edge count:       1281     Wake count:   5
Ready to sleep

�H��A�FSM wakeup from sleep
Edge count:       1537     Wake count:   6
Cancelling FSM program...
Final exit Xtensa program

Done

Here's excerpt of C++ code. Note, this is not a native ESP API in use.

Code: Select all

extern "C" 
void app_main( void )
{
    MicroControllerUnit* const mcu = new MicroControllerUnit();
    PowerManagementUnit* const pmu = mcu->getPowerManagementUnit();
    SleepAndWakeupController* const swc = pmu->getSleepAndWakeupController();
    CoprocessorULP* const ulp = mcu->getCoprocessorULP();
    CoreFSM* const fsm = ulp->getCoreFSM();
    TimerULP* const tmr = ulp->getTimerULP();
    CoreLX7* cpu = mcu->getProcessor( 0 );
    
    uint32_t cause = 0;
    if( swc->wakeup.isCause( SleepAndWakeupController::Peripherals::FSM ) ) 
    {
        printf( "\nULP FSM wakeup on system reset\n" );
        printf( "Edge count: %10d     Wake count: %3d\n", ulp_edge_count, ulp_wake_count );
        //if( ulp_wake_count >= 6 )
        {
            // Done. Stop both programs
            printf("Cancelling FSM program...\n");
            tmr->active->set( false );
            fsm->clockOn->set( false );
            printf("Abnormal exit Xtensa program\n");
            return;
        }
    } 
    else if( ( cause = swc->wakeup.cause->getAll() ) == 0 )
    {
        printf( "\nMCU reset 0x%02x\n", (uint32_t) cpu->getResetCause() );

        // cancel next timer run if any
        tmr->active->off(); 

        // load code
        BinaryImageULP image( ulp_main_bin_start, ulp_main_bin_end - ulp_main_bin_start );
        esp_err_t e = image.loadAt( RTC_SLOW_MEM );
        if( e != ESP_OK ) ...
        ulp->entry->set( &ulp_entry - RTC_SLOW_MEM );

        // init shared vars, not earlier than the program has been loaded 
        ulp_edge_count = 0;
        ulp_wake_count = 0;
        printf( "Edge count: %10d\n", ulp_edge_count );
        
        // select FSM to run
        fsm->selectForExec();
        fsm->selectForDone();
        fsm->startOn->off(); // block software start of ULP
        fsm->clockOn->on();
        fsm->clockOff->off();

        // allow auto PD for clocks only, see Table 195: Predefined Power Modes
        pmu->ctrl.wifi.sleepDn->off();
        pmu->ctrl.digital.sleepDn->off();
        //TODO how clocks OFF?
        pmu->ctrl.slowMemory.sleepDn->off();
        pmu->ctrl.fastMemory.sleepDn->off();
        pmu->ctrl.peripherals.sleepDn->off();

        // ensure power ON for RTC slow memory where FSM program resides
        pmu->ctrl.slowMemory.power->on->on();
        pmu->ctrl.slowMemory.power->off->off();
        pmu->ctrl.slowMemory.isolation->off->on();

        // allow Xtensa wakeup by FSM
        swc->wakeup.enable->setAll( false );
        swc->wakeup.setEnabled( SleepAndWakeupController::Peripherals::FSM, true );

        // start ULP timer
        tmr->sleep->set( 50 ); // 75+: rst:0x8 (TG1WDT_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
        tmr->active->on();
    }
    else
    {
        printf( "\nUnexpected wakeup cause %08x\n", cause );
    }
    
    while( ulp_wake_count < 6 )
    {
        // Get ready to sleep
        printf( "Ready to sleep\n\n" );
        fflush(stdout);
        suspend_uart(CONFIG_ESP_CONSOLE_UART_NUM);
        vTaskDelay( 20 );
        
        // enter light sleep
        swc->sleep.start->off(); // 
        swc->sleep.start->on(); // returns after wakeup from there

        // wait here until wakeup
        resume_uart(CONFIG_ESP_CONSOLE_UART_NUM);
        // while (GET_PERI_REG_MASK(RTC_CNTL_INT_RAW_REG,
        //                      RTC_CNTL_SLP_REJECT_INT_RAW | RTC_CNTL_SLP_WAKEUP_INT_RAW) == 0) {
        //     ;
        // }

        if( swc->wakeup.isCause( SleepAndWakeupController::Peripherals::FSM ) ) 
        {
            printf( "\nULP FSM wakeup from sleep\n" );
            printf( "Edge count: %10d     Wake count: %3d\n", ulp_edge_count, ulp_wake_count );
        }
        else
        {
            printf( "\nUnexpected wakeup cause %08x\n", cause );
            printf( "Edge count: %10d     Wake count: %3d\n", ulp_edge_count, ulp_wake_count );
        }
    }

    // Done. Stop both programs
    printf("Cancelling FSM program...\n");
    tmr->active->off();
    fsm->clockOn->off();
    printf("Final exit Xtensa program\n");
}

ESP-IDF code base: version 4.2