Open Tnze opened 1 day ago
@Tnze Based on the IDF version and chip name you provided, I was NOT able to reproduce the issue. I have included the log below. Also, please ensure that your codebase is clean and properly synced. Could you kindly share the sdkconfig file?
Log that I got :
I (23) bot: ESP-IDF v5.3.1 2nd stage bootloader I (24) boot: compile time Nov 13 2024 12:50:40 I (25) boot: chip revision: v0.2 I (27) boot.esp32h2: SPI Speed : 64MHz I (31) boot.esp32h2: SPI Mode : DIO I (36) boot.esp32h2: SPI Flash Size : 2MB I (41) boot: Enabling RNG early entropy source... I (46) boot: Partition Table: I (50) boot: ## Label Usage Type ST Offset Length I (57) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (64) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (72) boot: 2 factory factory app 00 00 00010000 00100000 I (80) boot: End of partition table I (84) esp_image: segment 0: paddr=00010020 vaddr=42080020 size=1b0f4h (110836) map I (126) esp_image: segment 1: paddr=0002b11c vaddr=40800000 size=04efch ( 20220) load I (134) esp_image: segment 2: paddr=00030020 vaddr=42000020 size=7e4dch (517340) map I (295) esp_image: segment 3: paddr=000ae504 vaddr=40804efc size=0f608h ( 62984) load I (317) esp_image: segment 4: paddr=000bdb14 vaddr=40814510 size=02cbch ( 11452) load I (322) esp_image: segment 5: paddr=000c07d8 vaddr=50000000 size=00050h ( 80) load I (324) esp_image: segment 6: paddr=000c0830 vaddr=50000050 size=00008h ( 8) load I (338) boot: Loaded app from partition at offset 0x10000 I (339) boot: Disabling RNG early entropy source... I (355) cpu_start: Unicore app W (1892) clk: 32 kHz clock not found, switching to internal 150 kHz oscillator I (1915) cpu_start: Pro cpu start user code I (1916) cpu_start: cpu freq: 96000000 Hz I (1916) app_init: Application information: I (1919) app_init: Project name: power_save I (1924) app_init: App version: v5.3.1 I (1929) app_init: Compile time: Nov 13 2024 12:50:35 I (1935) app_init: ELF file SHA256: 5a25a9141... I (1940) app_init: ESP-IDF: v5.3.1 I (1945) efuse_init: Min chip rev: v0.0 I (1950) efuse_init: Max chip rev: v0.99 I (1955) efuse_init: Chip rev: v0.2 I (1960) heap_init: Initializing. RAM available for dynamic allocation: I (1967) heap_init: At 40819F90 len 000333F0 (204 KiB): RAM I (1973) heap_init: At 4084D380 len 00002B60 (10 KiB): RAM I (1981) spi_flash: detected chip: generic I (1984) spi_flash: flash io: dio W (1988) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header. I (2002) sleep: Enable automatic switching of GPIO sleep configuration I (2009) sleep_clock: System Power, Clock and Reset sleep retention initialization I (2031) pm: Frequency switching config: CPU_MAX: 96, APB_MAX: 32, APB_MIN: 32, Light sleep: DISABLED I (2032) coexist: coex firmware version: 4482466 I (2037) main_task: Started on CPU0 I (2040) main_task: Calling app_main() I (2054) pm: Frequency switching config: CPU_MAX: 96, APB_MAX: 32, APB_MIN: 32, Light sleep: ENABLED W (2055) BLE_INIT: 32.768kHz XTAL not detected, fall back to main XTAL as Bluetooth sleep clock I (2063) BLE_INIT: Using main XTAL as clock source I (2075) BLE_INIT: ble controller commit:[a95ec45] W (2075) BLE_INIT: BLE modem sleep is enabled I (2080) BLE_INIT: Modem BLE MAC retention initialization W (2085) BLE_INIT: Enable light sleep, the wake up source is BLE timer I (2104) phy: phy_version: 310,2, 8fa9cb4, Jun 5 2024, 14:19:10 I (2122) phy: libbtbb version: a024da6, Jun 5 2024, 14:19:22 I (2123) sleep_clock: Modem Power, Clock and Reset sleep retention initialization I (2128) NimBLE_BLE_PRPH: BLE Host Task Started I (2135) NimBLE: Device Address: I (2136) NimBLE: 60:55:f9:f7:39:cc I (2139) NimBLE:
I (2143) NimBLE: GAP procedure initiated: extended advertise; instance=0
I (2153) uart: queue free spaces: 8 I (2155) main_task: Returned from app_main() I (13449) NimBLE: connection established; status=0 I (13450) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (13500) NimBLE: 60:55:f9:f7:39:cc I (13501) NimBLE: our_id_addr_type=0 our_id_addr= I (13502) NimBLE: 60:55:f9:f7:39:cc I (13504) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (13512) NimBLE: 50:6e:89:2d:aa:68 I (13514) NimBLE: peer_id_addr_type=1 peer_id_addr= I (13519) NimBLE: 50:6e:89:2d:aa:68 I (13524) NimBLE: conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (13534) NimBLE:
I (13538) NimBLE: advertise complete; reason=0 I (13544) NimBLE: GAP procedure initiated: extended advertise; instance=0
I (14137) NimBLE: connection updated; status=0 I (14138) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (14188) NimBLE: 60:55:f9:f7:39:cc I (14189) NimBLE: our_id_addr_type=0 our_id_addr= I (14189) NimBLE: 60:55:f9:f7:39:cc I (14192) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (14198) NimBLE: 50:6e:89:2d:aa:68 I (14203) NimBLE: peer_id_addr_type=1 peer_id_addr= I (14207) NimBLE: 50:6e:89:2d:aa:68 I (14211) NimBLE: conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (14222) NimBLE:
I (14710) NimBLE: connection updated; status=0 I (14712) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (14762) NimBLE: 60:55:f9:f7:39:cc I (14765) NimBLE: our_id_addr_type=0 our_id_addr= I (14765) NimBLE: 60:55:f9:f7:39:cc I (14768) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (14773) NimBLE: 50:6e:89:2d:aa:68 I (14778) NimBLE: peer_id_addr_type=1 peer_id_addr= I (14783) NimBLE: 50:6e:89:2d:aa:68 I (14787) NimBLE: conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (14800) NimBLE:
I (109905) NimBLE: disconnect; reason=531 I (109906) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (109957) NimBLE: 60:55:f9:f7:39:cc I (109958) NimBLE: our_id_addr_type=0 our_id_addr= I (109958) NimBLE: 60:55:f9:f7:39:cc I (109960) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (109968) NimBLE: 50:6e:89:2d:aa:68 I (109971) NimBLE: peer_id_addr_type=1 peer_id_addr= I (109976) NimBLE: 50:6e:89:2d:aa:68 I (109981) NimBLE: conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (109991) NimBLE:
I (121245) NimBLE: connection established; status=0 I (121296) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (121297) NimBLE: 60:55:f9:f7:39:cc I (121298) NimBLE: our_id_addr_type=0 our_id_addr= I (121302) NimBLE: 60:55:f9:f7:39:cc I (121306) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (121312) NimBLE: 50:6e:89:2d:aa:68 I (121317) NimBLE: peer_id_addr_type=1 peer_id_addr= I (121322) NimBLE: 50:6e:89:2d:aa:68 I (121327) NimBLE: conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (121337) NimBLE:
I (121342) NimBLE: advertise complete; reason=0 I (121348) NimBLE: GAP procedure initiated: extended advertise; instance=0
I (121526) NimBLE: Reattempt advertising; reason: 0x3e, status = 0 I (121578) NimBLE: GAP procedure initiated: stop extended advertising.
I (121585) NimBLE: GAP procedure initiated: extended advertise; instance=0
I (121742) NimBLE: connection established; status=0 I (121794) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (121795) NimBLE: 60:55:f9:f7:39:cc I (121796) NimBLE: our_id_addr_type=0 our_id_addr= I (121802) NimBLE: 60:55:f9:f7:39:cc I (121805) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (121810) NimBLE: 50:6e:89:2d:aa:68 I (121815) NimBLE: peer_id_addr_type=1 peer_id_addr= I (121820) NimBLE: 50:6e:89:2d:aa:68 I (121825) NimBLE: conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (121835) NimBLE:
I (121841) NimBLE: advertise complete; reason=0 I (121848) NimBLE: GAP procedure initiated: extended advertise; instance=0
I (122025) NimBLE: Reattempt advertising; reason: 0x3e, status = 0 I (122077) NimBLE: GAP procedure initiated: stop extended advertising.
I (122082) NimBLE: GAP procedure initiated: extended advertise; instance=0
I (122201) NimBLE: connection established; status=0 I (122252) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (122253) NimBLE: 60:55:f9:f7:39:cc I (122254) NimBLE: our_id_addr_type=0 our_id_addr= I (122258) NimBLE: 60:55:f9:f7:39:cc I (122263) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (122271) NimBLE: 50:6e:89:2d:aa:68 I (122273) NimBLE: peer_id_addr_type=1 peer_id_addr= I (122279) NimBLE: 50:6e:89:2d:aa:68 I (122283) NimBLE: conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (122293) NimBLE:
I (122297) NimBLE: advertise complete; reason=0 I (122304) NimBLE: GAP procedure initiated: extended advertise; instance=0
I (123193) NimBLE: connection updated; status=0 I (123195) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (123245) NimBLE: 60:55:f9:f7:39:cc I (123246) NimBLE: our_id_addr_type=0 our_id_addr= I (123246) NimBLE: 60:55:f9:f7:39:cc I (123249) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (123256) NimBLE: 50:6e:89:2d:aa:68 I (123259) NimBLE: peer_id_addr_type=1 peer_id_addr= I (123266) NimBLE: 50:6e:89:2d:aa:68 I (123269) NimBLE: conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (123279) NimBLE:
I (123825) NimBLE: connection updated; status=0 I (123826) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (123876) NimBLE: 60:55:f9:f7:39:cc I (123879) NimBLE: our_id_addr_type=0 our_id_addr= I (123880) NimBLE: 60:55:f9:f7:39:cc I (123882) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (123888) NimBLE: 50:6e:89:2d:aa:68 I (123892) NimBLE: peer_id_addr_type=1 peer_id_addr= I (123898) NimBLE: 50:6e:89:2d:aa:68 I (123902) NimBLE: conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (123914) NimBLE:
I (304007) NimBLE: disconnect; reason=531 I (304009) NimBLE: handle=0 our_ota_addr_type=0 our_ota_addr= I (304059) NimBLE: 60:55:f9:f7:39:cc I (304060) NimBLE: our_id_addr_type=0 our_id_addr= I (304061) NimBLE: 60:55:f9:f7:39:cc I (304063) NimBLE: peer_ota_addr_type=1 peer_ota_addr= I (304069) NimBLE: 50:6e:89:2d:aa:68 I (304073) NimBLE: peer_id_addr_type=1 peer_id_addr= I (304079) NimBLE: 50:6e:89:2d:aa:68 I (304083) NimBLE: conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
I (304093) NimBLE:
Looks like you didn't reproduce the assertion failure and panic.
While capturing the logs my codebase is not clean because I applied a patch from #16864. But I can ensure the issue can be reproduced on unmodified esp-idf release. I will clean the code and recapture the logs, sharing the config file later.
I cleanup my esp-idf and I can still reproduce this issue. And this is my project (with built artifacts). power_save.zip.001.zip power_save.zip.002.zip
Answers checklist.
IDF version.
v5.3.1
Espressif SoC revision.
ESP32-H2
Operating System used.
Windows
How did you build your project?
VS Code IDE
If you are using Windows, please specify command line type.
PowerShell
Development Kit.
Waveshare ESP32-H2-DEV-KIT-N4
Power Supply used.
USB
What is the expected behavior?
The example doesn't panic. And the BLE works.
What is the actual behavior?
When connected from an iPhone, the ESP-32 panic and reboot. After crashing and restarting several times, and connecting several times, the connection can then be successful.
Steps to reproduce.
power save
examplenimble-bleprph-e
Debug Logs.
More Information.
It's noticed that the rear part of the logs is quite similar to #12911