espressif / esp-zigbee-sdk

Espressif Zigbee SDK
Apache License 2.0
171 stars 30 forks source link

Light Sleep asserts in idf code (TZ-1278) #473

Open asward opened 5 days ago

asward commented 5 days ago

Answers checklist.

IDF version.

v5.4

esp-zigbee-lib version.

1.5.1

esp-zboss-lib version.

1.5.1

Espressif SoC revision.

ESP32-C6

What is the expected behavior?

Following (to the best of my ability) the light sleep documentation for the zigbee-sdk I am expect the zigbee device to continue to sleep/wake forever.

What is the actual behavior?

The device works normally for several cycles but inevitably ends in the assert logged below

Steps to reproduce.

Ref https://github.com/asward/espc6-zb-troubleshoot for environment config.

More Information.

Rebooting...
ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0xc (SW_CPU),boot:0xc (SPI_FAST_FLASH_BOOT)
Saved PC:0x4001975a
SPIWP:0xee
mode:DIO, clock div:2
load:0x40875720,len:0x18ec
load:0x4086c110,len:0xe84
load:0x4086e610,len:0x2f34
entry 0x4086c11a
I (26) boot: ESP-IDF v5.4-dev-3432-g906f36bdb9 2nd stage bootloader
I (27) boot: compile time Nov 10 2024 21:14:26
I (28) boot: chip revision: v0.0
I (31) boot: efuse block revision: v0.1
I (36) boot.esp32c6: SPI Speed      : 80MHz
I (41) boot.esp32c6: SPI Mode       : DIO
I (45) boot.esp32c6: SPI Flash Size : 4MB
I (50) boot: Enabling RNG early entropy source...
I (56) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (74) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (81) boot:  2 factory          factory app      00 00 00010000 001e0000
I (89) boot:  3 zb_storage       Unknown data     01 81 001f0000 00010000
I (96) boot:  4 zb_fct           Unknown data     01 81 00200000 00001000
I (104) boot: End of partition table
I (108) esp_image: segment 0: paddr=00010020 vaddr=42060020 size=11464h ( 70756) map
I (143) esp_image: segment 1: paddr=0002148c vaddr=40800000 size=0eb8ch ( 60300) load
I (169) esp_image: segment 2: paddr=00030020 vaddr=42000020 size=5755ch (357724) map
I (300) esp_image: segment 3: paddr=00087584 vaddr=4080eb8c size=0367ch ( 13948) load
--- 0x4001975a: software_reset_cpu in ROM

I (307) esp_image: segment 4: paddr=0008ac08 vaddr=40812210 size=021bch (  8636) load
I (313) esp_image: segment 5: paddr=0008cdcc vaddr=50000000 size=00050h (    80) load
I (315) esp_image: segment 6: paddr=0008ce24 vaddr=50000050 size=0001ch (    28) load
I (332) boot: Loaded app from partition at offset 0x10000
I (332) boot: Disabling RNG early entropy source...
I (347) cpu_start: Unicore app
I (356) cpu_start: Pro cpu start user code
I (356) cpu_start: cpu freq: 160000000 Hz
I (356) app_init: Application information:
I (359) app_init: Project name:     project-name
I (364) app_init: App version:      1
I (368) app_init: Compile time:     Nov 10 2024 21:46:03
I (374) app_init: ELF file SHA256:  e02ecd01a...
I (380) app_init: ESP-IDF:          v5.4-dev-3432-g906f36bdb9
I (386) efuse_init: Min chip rev:     v0.0
I (391) efuse_init: Max chip rev:     v0.99 
I (396) efuse_init: Chip rev:         v0.0
I (401) heap_init: Initializing. RAM available for dynamic allocation:
I (408) heap_init: At 40818B40 len 00063AD0 (398 KiB): RAM
I (414) heap_init: At 4087C610 len 00002F54 (11 KiB): RAM
I (420) heap_init: At 5000006C len 00003F7C (15 KiB): RTCRAM
I (427) spi_flash: detected chip: generic
I (431) spi_flash: flash io: dio
I (435) sleep_gpio: Enable automatic switching of GPIO sleep configuration
I (443) sleep_clock: System Power, Clock and Reset sleep retention initialization
I (478) pm: Frequency switching config: CPU_MAX: 160, APB_MAX: 80, APB_MIN: 40, Light sleep: DISABLED
I (478) coexist: coex firmware version: 49d5b702e
I (482) coexist: coexist rom version 5b8dcfa
I (487) main_task: Started on CPU0
I (490) main_task: Calling app_main()
I (498) APP: Starting ZigBee
I (498) pm: Frequency switching config: CPU_MAX: 160, APB_MAX: 160, APB_MIN: 160, Light sleep: ENABLED
I (509) esp_zb_sleep: Enable ieee802154 zigbee light sleep, the wake up source is ESP timer
I (518) phy_init: phy_version 320,348a293,Sep  3 2024,16:33:12
W (555) phy_init: saving new calibration data because of checksum failure, mode(0)
I (566) phy: libbtbb version: 04952fd, Sep  3 2024, 16:33:30
I (566) sleep_clock: Modem Power, Clock and Reset sleep retention initialization
I (571) APP: Registering
I (574) APP: Reporting Conf Updated
I (577) ESP_ZB: Endpoint Task Started
I (590) APP: Task Completed
I (590) main_task: Returned from app_main()
I (592) ESP_ZB: Initialize Zigbee stack
ESP_ZB Sleeping
ESP_ZB Waking
Returned from light sleep, reason: other (0), t=225 ms, slept for 54 ms
ESP_ZB Sleeping
ESP_ZB Waking
Returned from light sleep, reason: other (0), t=251 ms, slept for 25 ms

... a few seconds later ...

Returned from light sleep, reason: other (0), t=99402 ms, slept for 571 ms
ESP_ZB Sleeping

assert failed: esp_sleep_pd_config sleep_modes.c:2188 (refs >= 0)
Core  0 register dump:
--- Stack dump detected
MEPC    : 0x40800948  RA      : 0x4080b91e  SP      : 0x4081dad0  GP      : 0x40812a14  
--- 0x40800948: panic_abort at /opt/esp/idf/components/esp_system/panic.c:468
0x4080b91e: esp_task_wdt_reset at /opt/esp/idf/components/esp_system/task_wdt/task_wdt.c:695

TP      : 0x4081dc60  T0      : 0x37363534  T1      : 0x7271706f  T2      : 0x33323130  
S0/FP   : 0x00000086  S1      : 0x00000001  A0      : 0x4081db0c  A1      : 0x40813561  
A2      : 0x00000001  A3      : 0x00000029  A4      : 0x00000001  A5      : 0x40819000  
A6      : 0x0000000c  A7      : 0x76757473  S2      : 0x00000009  S3      : 0x4081dc21  
S4      : 0x40813560  S5      : 0x00000000  S6      : 0x00000000  S7      : 0x00000000  
S8      : 0x00000000  S9      : 0x00000000  S10     : 0x00000000  S11     : 0x00000000  
T3      : 0x6e6d6c6b  T4      : 0x6a696867  T5      : 0x66656463  T6      : 0x62613938  
MSTATUS : 0x00001881  MTVEC   : 0x40800001  MCAUSE  : 0x00000002  MTVAL   : 0x00000000  
--- 0x40800001: _vector_table at /opt/esp/idf/components/riscv/vectors_intc.S:54

MHARTID : 0x00000000  

--- Backtrace:

panic_abort (details=details@entry=0x4081db0c "assert failed: esp_sleep_pd_config sleep_modes.c:2188 (refs >= 0)") at /opt/esp/idf/components/esp_system/panic.c:468
468         asm("unimp");   // should be an invalid operation on RISC-V targets
#0  panic_abort (details=details@entry=0x4081db0c "assert failed: esp_sleep_pd_config sleep_modes.c:2188 (refs >= 0)") at /opt/esp/idf/components/esp_system/panic.c:468
#1  0x4080b91e in esp_system_abort (details=details@entry=0x4081db0c "assert failed: esp_sleep_pd_config sleep_modes.c:2188 (refs >= 0)") at /opt/esp/idf/components/esp_system/port/esp_system_chip.c:92
#2  0x40811122 in __assert_func (file=file@entry=0x420615ec "", line=line@entry=2188, func=<optimized out>, func@entry=0x4206cea0 <__func__.4> "", expr=expr@entry=0x4206139c "") at /opt/esp/idf/components/newlib/assert.c:80
#3  0x42054710 in esp_sleep_pd_config (domain=domain@entry=ESP_PD_DOMAIN_RTC_PERIPH, option=option@entry=ESP_PD_OPTION_ON) at /opt/esp/idf/components/esp_hw_support/sleep_modes.c:2188
#4  0x4080435a in vApplicationSleep (xExpectedIdleTime=351) at /opt/esp/idf/components/esp_pm/pm_impl.c:820
#5  0x4080dd2a in prvIdleTask (pvParameters=<error reading variable: value has been optimized out>) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/tasks.c:4379
#6  0x4080c9cc in vPortTaskWrapper (pxCode=<optimized out>, pvParameters=<optimized out>) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/portable/riscv/port.c:255
xieqinan commented 23 hours ago

@asward

Following (to the best of my ability) the light sleep documentation for the zigbee-sdk I am expect the zigbee device to continue to sleep/wake forever.

Could you please share the changes you've made based on the light sleep example to implement the feature?

asward commented 7 hours ago

I used the documentation(s) from Espressif: https://docs.espressif.com/projects/esp-idf/en/v5.3.1/esp32/api-reference/system/power_management.html?highlight=light%20sleep

https://docs.espressif.com/projects/esp-idf/en/v5.3.1/esp32/api-reference/system/sleep_modes.html?highlight=light%20sleep

https://docs.espressif.com/projects/esp-zigbee-sdk/en/latest/esp32/index.html

The code is not forked from the example code. I used idf.py to generate the template project and removed the original app code. It's difficult to 'diff' that other than what I've provided above. Not sure what else we're looking for. It's hard for me to debug or even troubleshoot this because it works fine for a few moments, and the error is buried in library code.