how to see what is waking up esp32-c6 project in light sleep

[pmurdock]

G'day!

have a project testing out light sleep mode with 30 second interval to wake up, however esp32-c6 dev board seems to be waking up regularly.. using a nrf power profiler to measure current.. see attached

Screenshot 2024-10-13 214502.png (127.01 KiB) Viewed 823 times

when it actually is in sleep i use around 60uA.. however, it seems to be waking up at regular intervals.. turning on debug output doesn't reveal what is waking it up.. my code does start printing uart again at 30 seconds as it think it woke up, but something else is waking it up at a regular cadence..

does anyone have suggestions on how best to identify what it is that might be waking it up?

a) i tried esp_timer_dump() before I go to sleep to see if I could see any timers setup to wake up... didn't see anything obvious.

b) debug output did show this

Code: Select all

I (134284) PCM_MAIN_APP: STATE_MACHINE - MAS_Sleep
D (134304) pmu_sleep: blk_version is less than 3, lsD (134414) pmu_sleep: blk_version is less than 3, lsD (135114) pmu_sleep: blk_version is less than 3, lsD (136114) pmu_sleep: blk_version is less than 3, lsD (137114) pmu_sleep: blk_version is less than 3, lsD (137234) pmu_sleep: blk_version is less than

but my sense was that was because debug was turned on.. although it did seem to print at the same cadence as the spikes, but I couldn't make sense of what that was referring to.

mainly just thinking about how best to debug unknown wakeups

cheers!
Paul

[pmurdock]

Here's some more additional informmation.. this is the output with DEBUG output turned on.. I did an esp_timer_dump() to see if I could understand what timers were coming up that might be doing this triggering.. I think i may have caught the timer details but struggling to nail down what task it is associated with.. see this line

Code: Select all

Timer stats:
Name                  Period      Alarm       
timer@0x4083ad78      1000000     41034585   
 

I thought I might be able to find out in the MAP file where 0x4083ad78 points to, but it seems to be in the heap.. which is allocated at runtime I'm assuming for tasks.. is there a good way to track down where that timer is coming from? 1million usec is 1 second which would seemingly be the timer which is waking my light sleep up.. BUT how to know where that timer is coming from?



Overall DEBUG output surrounding the sleep

Code: Select all

I (40412) mqtt_client: Client asked to disconnect
I (40422) mod_wifi: Wi-Fi Phy mode: PHY mode for Bandwidth HE20
I (40442) wifi:Set ps type: 1, coexist: 0

D (40452) event: running post WIFI_EVENT:28 with handler 0x42014858 and context 0x4083acc8 on loop 0x4082c854
--- 0x42014858: mod_wifi_handler_itwt_setup at /home/pmurdock/Documents/repos/WiFi6_PwrTest/components/MOD_WiFi/mod_wifi.c:617

I (40452) mod_wifi: <WIFI_EVENT_ITWT_SETUP>twt_id:0, flow_id:1, non-trigger-enabled, unannounced, wake_dura:255, wake_invl_e:9, wake_invl_m:58594
I (40462) mod_wifi: <WIFI_EVENT_ITWT_SETUP>wake duration:65280 us, service period:30000128 us
D (40472) event: running post MOD_WIFI_EVENTS:3 with handler 0x42014388 and context 0x4082e7ac on loop 0x4082d790
--- 0x42014388: mod_pwr_wifi_events_handler at /home/pmurdock/Documents/repos/WiFi6_PwrTest/components/MOD_Power/mod_pwr.c:208

I (40482) mod_pwr: iTWT established
I (40482) mod_pwr: Sleep time: 30 seconds

I (40492) pm: Frequency switching config: CPU_MAX: 80, APB_MAX: 80, APB_MIN: 10, Light sleep: ENABLED
D (40502) event: running post MOD_POWER_EVENTS:0 with handler 0x4200ed72 and context 0x4082e6c4 on loop 0x4082d790
--- 0x4200ed72: PWR_events_handler at /home/pmurdock/Documents/repos/WiFi6_PwrTest/main/main.c:220

I (40512) PCM_MAIN_APP: Going to sleep.
I (40512) PCM_MAIN_APP: Sleep time:30
I (40532) PCM_MAIN_APP: STATE_MACHINE - MAS_Sleep
Timer stats:
Name                  Period      Alarm       
timer@0x4083ad78      1000000     41034585    
timer@0x408382a8      0           46840465    
timer@0x4083b028      0           20639010244 
timer@0x40839de8      0           50072247510 
D (40552) pmu_sleep: blk_version is less than 3, lD (41012) pmu_sleep: blk_version is less than 3, lD (42002) pmu_sleep: blk_version is less than 3, lD (43002) pmu_sleep: blk_version is less than 3, l

[boarchuz]

I recall lwIP's TCP slow timer having an annoying wakeup pattern like this, even when all networking is idle.

I think I may have also seen a very recent ESP-IDF commit to address this

[pmurdock]

Thanks I'll investigate that.. I think for me the key to the question is how to generally debug such a problem .. I had hoped dumping the timers would have given me all the info I needed to debug it, but it wasn't obvious (at least to me) to even know to look at the iwIP task as the culprit.. is there a better way to debug?