project-chip / connectedhomeip

Matter (formerly Project CHIP) creates more connections between more objects, simplifying development for manufacturers and increasing compatibility for consumers, guided by the Connectivity Standards Alliance.
https://buildwithmatter.com
Apache License 2.0
7.34k stars 1.97k forks source link

[1.2] #31463

Open solstice-gao opened 8 months ago

solstice-gao commented 8 months ago

Reproduction steps

Use esp-idf to burn normally esp32-c3

Bug prevalence

every esp32c3 board

GitHub hash of the SDK that was being used

123

Platform

esp32

Platform Version(s)

1.2

Type

Platform Issue

Anything else?

The following is the running log.He has been printing the following logs in the console even if there is no operation.I changed the development board and it's still the same.

LOG: [0;32mI (1184) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)[0m [0;32mI (1184) NimBLE: GAP procedure initiated: advertise; [0m [0;32mI (1184) NimBLE: disc_mode=2[0m [0;32mI (1184) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40[0m [0;32mI (1194) NimBLE: [0m [0;32mI (1204) chip[DL]: CHIPoBLE advertising started[0m [0;32mI (1204) chip[DL]: Starting ESP WiFi layer[0m I (1214) wifi:mode : sta (48:31:b7:06:47:c0) I (1214) wifi:enable tsf W (1214) wifi:Haven't to connect to a suitable AP now! [0;32mI (1224) chip[DL]: Done driving station state, nothing else to do...[0m W (1224) wifi:Haven't to connect to a suitable AP now! [0;32mI (1234) chip[DL]: Done driving station state, nothing else to do...[0m [0;32mI (1244) chip[SVR]: Initializing subscription resumption storage...[0m [0;32mI (1244) chip[SVR]: Server initializing...[0m [0;32mI (1254) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48[0m [0;32mI (1254) chip[DMG]: AccessControl: initializing[0m

[0;32mI (1264) chip[DMG]: AccessControl: setting[0m [0;32mI (1274) chip[DMG]: DefaultAclStorage: initializing[0m [0;32mI (1284) chip[DMG]: DefaultAclStorage: 0 entries loaded[0m [0;32mI (1294) chip[ZCL]: Using ZAP configuration...[0m [0;32mI (1294) chip[DMG]: AccessControlCluster: initializing[0m [0;32mI (1294) chip[ZCL]: Initiating Admin Commissioning cluster.[0m [0;32mI (1304) chip[ZCL]: Door Lock server initialized[0m [0;32mI (1304) lock-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x30', EndPoint ID: '0x0', Attribute ID: '0x0'[0m [0;32mI (1314) lock-devicecallbacks: Unhandled cluster ID: 48[0m [0;32mI (1324) lock-devicecallbacks: Current free heap: 100420 [0m [0;32mI (1334) chip[DIS]: Updating services using commissioning mode 1[0m [0;32mI (1334) chip[DIS]: CHIP minimal mDNS started advertising.[0m [0;32mI (1344) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32774 discriminator=3840/15 cm=1[0m [0;32mI (1354) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 0AEAE7826CF80BE3.[0m [0;32mI (1364) chip[DIS]: mDNS service published: _matterc._udp[0m [0;32mI (1374) chip[IN]: CASE Server enabling CASE session setups[0m [0;32mI (1374) chip[SVR]: Joining Multicast groups[0m [0;32mI (1384) chip[SVR]: Server Listening...[0m [0;32mI (1384) lock-app: ------------------------Starting App Task---------------------------[0m [0;32mI (1394) app-devicecallbacks: Current free heap: 95992 [0m

W (1404) wifi:Haven't to connect to a suitable AP now! [0;32mI (1414) chip[DL]: Done driving station state, nothing else to do...[0m [0;32mI (1414) app-devicecallbacks: Current free heap: 95964 DL: Configuring CHIPoBLE advertising (interval 25 ms, connectable)[0m [0;32mI (1434) chip[DL]: Device already advertising, stop active advertisement and restart[0m [0;32mI (1444) NimBLE: GAP procedure initiated: stop advertising. [0m [0;32mI (1444) NimBLE: GAP procedure initiated: advertise; [0m [0;32mI (1454) NimBLE: disc_mode=2[0m [0;32mI (1454) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40[0m [0;32mI (1464) NimBLE: [0m [0;32mI (1474) chip[DL]: Device Configuration:[0m [0;32mI (1474) chip[DL]: Serial Number: TEST_SN[0m [0;32mI (1474) chip[DL]: Vendor Id: 65521 (0xFFF1)[0m [0;32mI (1484) chip[DL]: Product Id: 32774 (0x8006)[0m [0;32mI (1494) chip[DL]: Product Name: TEST_PRODUCT[0m [0;32mI (1494) chip[DL]: Hardware Version: 0[0m [0;32mI (1504) chip[DL]: Setup Pin Code (0 for UNKNOWN/ERROR): 20202021[0m [0;32mI (1504) chip[DL]: Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)[0m [0;32mI (1514) chip[DL]: Manufacturing Date: (not set)[0m [0;32mI (1524) chip[DL]: Device Type: 0 (0x0)[0m [0;32mI (1524) chip[SVR]: SetupQRCode: [MT:8IXS142C00KA0648G00][0m [0;32mI (1534) chip[SVR]: Copy/paste the below URL in a browser to see the QR Code:[0m

[0;32mI (1554) chip[SVR]: Manual pairing code: [34970112332][0m [0;32mI (1554) lock-app: App Task started[0m [0;32mI (1554) lock-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x6', EndPoint ID: '0x1', Attribute ID: '0x0'[0m [0;32mI (1574) lock-devicecallbacks: Current free heap: 95912 [0m [0;32mI (5384) lock-app: Factory Reset Triggered. Release button within 3000ms to cancel.[0m [0;32mI (8384) chip[TS]: Pending Last Known Good Time: 2023-10-14T01:16:48[0m [0;32mI (8384) chip[TS]: Previous Last Known Good Time: 2023-10-14T01:16:48[0m [0;32mI (8384) chip[TS]: Reverted Last Known Good Time to previous value[0m [0;32mI (8394) chip[DL]: Performing factory reset[0m I (8404) wifi:flush txq I (8404) wifi:stop sw txq I (8404) wifi:lmac stop hw txq [0;32mI (8414) chip[DL]: System restarting[0m ESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x3 (RTC_SW_SYS_RST),boot:0xf (SPI_FAST_FLASH_BOOT) Saved PC:0x40048b82 SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd5820,len:0x171c load:0x403cc710,len:0x968 load:0x403ce710,len:0x2f9c entry 0x403cc710 [0;32mI (24) boot: ESP-IDF v5.1.1-577-g6b1f40b9bf-dirty 2nd stage bootloader[0m [0;32mI (24) boot: compile time Jan 17 2024 09:02:29[0m [0;32mI (25) boot: chip revision: v0.4[0m [0;32mI (29) boot.esp32c3: SPI Speed : 80MHz[0m [0;32mI (34) boot.esp32c3: SPI Mode : DIO[0m [0;32mI (38) boot.esp32c3: SPI Flash Size : 2MB[0m [0;32mI (43) boot: Enabling RNG early entropy source...[0m [0;32mI (48) boot: Partition Table:[0m [0;32mI (52) boot: ## Label Usage Type ST Offset Length[0m [0;32mI (59) boot: 0 nvs WiFi data 01 02 00009000 0000c000[0m [0;32mI (67) boot: 1 phy_init RF data 01 01 00015000 00001000[0m [0;32mI (74) boot: 2 factory factory app 00 00 00020000 001e0000[0m [0;32mI (82) boot: End of partition table[0m [0;32mI (86) esp_image: segment 0: paddr=00020020 vaddr=3c100020 size=3b098h (241816) map[0m [0;32mI (134) esp_image: segment 1: paddr=0005b0c0 vaddr=3fc93800 size=033a0h ( 13216) load[0m [0;32mI (136) esp_image: segment 2: paddr=0005e468 vaddr=40380000 size=01bb0h ( 7088) load[0m [0;32mI (141) esp_image: segment 3: paddr=00060020 vaddr=42000020 size=f3928h (997672) map[0m [0;32mI (310) esp_image: segment 4: paddr=00153950 vaddr=40381bb0 size=11ab4h ( 72372) load[0m [0;32mI (330) boot: Loaded app from partition at offset 0x20000[0m [0;32mI (330) boot: Disabling RNG early entropy source...[0m [0;32mI (342) cpu_start: Unicore app[0m [0;32mI (342) cpu_start: Pro cpu up.[0m [0;32mI (351) cpu_start: Pro cpu start user code[0m [0;32mI (351) cpu_start: cpu freq: 160000000 Hz[0m [0;32mI (351) cpu_start: Application information:[0m [0;32mI (354) cpu_start: Project name: chip-lock-app[0m [0;32mI (359) cpu_start: App version: v1.0[0m [0;32mI (364) cpu_start: Compile time: Jan 17 2024 09:02:25[0m [0;32mI (370) cpu_start: ELF file SHA256: 35bf680aa81b85bc...[0m [0;32mI (376) cpu_start: ESP-IDF: v5.1.1-577-g6b1f40b9bf-dirty[0m [0;32mI (383) cpu_start: Min chip rev: v0.3[0m [0;32mI (387) cpu_start: Max chip rev: v0.99 [0m [0;32mI (392) cpu_start: Chip rev: v0.4[0m [0;32mI (397) heap_init: Initializing. RAM available for dynamic allocation:[0m [0;32mI (404) heap_init: At 3FCA7900 len 00034E10 (211 KiB): DRAM[0m [0;32mI (410) heap_init: At 3FCDC710 len 00002950 (10 KiB): STACK/DRAM[0m [0;32mI (417) heap_init: At 50000010 len 00001FD8 (7 KiB): RTCRAM[0m [0;32mI (424) spi_flash: detected chip: generic[0m [0;32mI (428) spi_flash: flash io: dio[0m [0;33mW (432) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.[0m [0;32mI (446) sleep: Configure to isolate all GPIO pins in sleep state[0m [0;32mI (452) sleep: Enable automatic switching of GPIO sleep configuration[0m [0;32mI (459) coexist: coex firmware version: 8770c12[0m [0;32mI (464) coexist: coexist rom version 9387209[0m [0;32mI (469) app_start: Starting scheduler on CPU0[0m [0;32mI (474) main_task: Started on CPU0[0m [0;32mI (474) main_task: Calling app_main()[0m [0;32mI (484) lock-app: ==================================================[0m [0;32mI (484) lock-app: chip-esp32-lock-example starting[0m [0;32mI (494) lock-app: ==================================================[0m [0;32mI (494) pp: pp rom version: 9387209[0m [0;32mI (504) net80211: net80211 rom version: 9387209[0m I (514) wifi:wifi driver task: 3fcb1854, prio:23, stack:6656, core=0 I (524) wifi:wifi firmware version: dc6ffb6 I (524) wifi:wifi certification version: v7.0 I (524) wifi:config NVS flash: enabled I (524) wifi:config nano formating: disabled I (524) wifi:Init data frame dynamic rx buffer num: 32 I (534) wifi:Init static rx mgmt buffer num: 5 I (534) wifi:Init management short buffer num: 32 I (544) wifi:Init dynamic tx buffer num: 32 I (544) wifi:Init static tx FG buffer num: 2 I (554) wifi:Init static rx buffer size: 1600 I (554) wifi:Init static rx buffer num: 10 I (554) wifi:Init dynamic rx buffer num: 32 [0;32mI (564) wifi_init: rx ba win: 6[0m [0;32mI (564) wifi_init: tcpip mbox: 32[0m [0;32mI (564) wifi_init: udp mbox: 6[0m [0;32mI (574) wifi_init: tcp mbox: 6[0m [0;32mI (574) wifi_init: tcp tx win: 5744[0m [0;32mI (584) wifi_init: tcp rx win: 5744[0m [0;32mI (584) wifi_init: tcp mss: 1440[0m [0;32mI (584) wifi_init: WiFi IRAM OP enabled[0m [0;32mI (594) wifi_init: WiFi RX IRAM OP enabled[0m [0;32mI (614) chip[DL]: NVS set: chip-counters/reboot-count = 1 (0x1)[0m [0;32mI (614) chip[DL]: NVS set: chip-counters/total-hours = 0 (0x0)[0m [0;32mI (614) chip[DL]: NVS set: chip-config/unique-id = "9ED80134E73C992E"[0m [0;32mI (624) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC)[0m [0;32mI (624) BLE_INIT: BT controller compile version [59725b5][0m [0;32mI (634) main_task: Returned from app_main()[0m [0;32mI (634) BLE_INIT: Bluetooth MAC: 48:31:b7:06:47:c2 [0m [0;32mI (644) phy_init: phy_version 1130,b4e4b80,Sep 5 2023,11:09:30[0m [0;32mI (684) NimBLE: GAP procedure initiated: stop advertising. [0m [0;32mI (684) NimBLE: Failed to restore IRKs from store; status=8 [0m [0;32mI (694) CHIP[DL]: BLE host-controller synced[0m [0;32mI (1194) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)[0m [0;32mI (1194) NimBLE: GAP procedure initiated: advertise; [0m [0;32mI (1194) NimBLE: disc_mode=2[0m [0;32mI (1194) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40[0m [0;32mI (1204) NimBLE: [0m [0;32mI (1214) chip[DL]: CHIPoBLE advertising started[0m [0;32mI (1214) chip[DL]: Starting ESP WiFi layer[0m I (1224) wifi:mode : sta (48:31:b7:06:47:c0) I (1224) wifi:enable tsf W (1224) wifi:Haven't to connect to a suitable AP now! [0;32mI (1234) chip[DL]: Done driving station state, nothing else to do...[0m W (1234) wifi:Haven't to connect to a suitable AP now! [0;32mI (1244) chip[DL]: Done driving station state, nothing else to do...[0m [0;32mI (1254) chip[SVR]: Initializing subscription resumption storage...[0m [0;32mI (1254) chip[SVR]: Server initializing...[0m [0;32mI (1264) chip[TS]: Last Known Good Time: [unknown][0m [0;32mI (1264) chip[TS]: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48[0m [0;32mI (1274) chip[DMG]: AccessControl: initializing[0m

[0;32mI (1284) chip[DMG]: AccessControl: setting[0m [0;32mI (1294) chip[DMG]: DefaultAclStorage: initializing[0m [0;32mI (1294) chip[DMG]: DefaultAclStorage: 0 entries loaded[0m [0;32mI (1304) chip[ZCL]: Using ZAP configuration...[0m [0;32mI (1314) chip[DMG]: AccessControlCluster: initializing[0m [0;32mI (1314) chip[ZCL]: Initiating Admin Commissioning cluster.[0m [0;32mI (1324) chip[ZCL]: Door Lock server initialized[0m [0;32mI (1324) lock-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x30', EndPoint ID: '0x0', Attribute ID: '0x0'[0m [0;32mI (1334) lock-devicecallbacks: Unhandled cluster ID: 48[0m [0;32mI (1344) lock-devicecallbacks: Current free heap: 100420 [0m [0;32mI (1354) chip[DIS]: Updating services using commissioning mode 1[0m [0;32mI (1354) chip[DIS]: CHIP minimal mDNS started advertising.[0m [0;32mI (1364) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32774 discriminator=3840/15 cm=1[0m [0;32mI (1374) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: F17540A5A2FC6E29.[0m [0;32mI (1384) chip[DIS]: mDNS service published: _matterc._udp[0m [0;32mI (1394) chip[IN]: CASE Server enabling CASE session setups[0m [0;32mI (1394) chip[SVR]: Joining Multicast groups[0m [0;32mI (1404) chip[SVR]: Server Listening...[0m [0;32mI (1404) lock-app: ------------------------Starting App Task---------------------------[0m [0;32mI (1414) app-devicecallbacks: Current free heap: 95992 [0m

W (1424) wifi:Haven't to connect to a suitable AP now! [0;32mI (1434) chip[DL]: Done driving station state, nothing else to do...[0m [0;32mI (1434) app-devicecallbacks: Current free heap: 95992 [0m [0;32mI (1444) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)[0m [0;32mI (1454) chip[DL]: Device already advertising, stop active advertisement and restart[0m [0;32mI (1464) NimBLE: GAP procedure initiated: stop advertising. [0m [0;32mI (1464) NimBLE: GAP procedure initiated: advertise; [0m [0;32mI (1474) NimBLE: disc_mode=2[0m [0;32mI (1474) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40[0m [0;32mI (1484) NimBLE: [0m [0;32mI (1484) chip[DL]: Device Configuration:[0m [0;32mI (1494) chip[DL]: Serial Number: TEST_SN[0m [0;32mI (1494) chip[DL]: Vendor Id: 65521 (0xFFF1)[0m [0;32mI (1504) chip[DL]: Product Id: 32774 (0x8006)[0m [0;32mI (1504) chip[DL]: Product Name: TEST_PRODUCT[0m [0;32mI (1514) chip[DL]: Hardware Version: 0[0m [0;32mI (1514) chip[DL]: Setup Pin Code (0 for UNKNOWN/ERROR): 20202021[0m [0;32mI (1524) chip[DL]: Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)[0m [0;32mI (1534) chip[DL]: Manufacturing Date: (not set)[0m [0;32mI (1534) chip[DL]: Device Type: 0 (0x0)[0m [0;32mI (1544) chip[SVR]: SetupQRCode: [MT:8IXS142C00KA0648G00][0m [0;32mI (1544) chip[SVR]: Copy/paste the below URL in a browser to see the QR Code:[0m

[0;32mI (1564) chip[SVR]: Manual pairing code: [34970112332][0m [0;32mI (1574) lock-app: App Task started[0m [0;32mI (1574) lock-devicecallbacks: PostAttributeChangeCallback - Cluster ID: '0x6', EndPoint ID: '0x1', Attribute ID: '0x0'[0m [0;32mI (1584) lock-devicecallbacks: Current free heap: 95912 [0m [0;32mI (5034) lock-app: Factory Reset Triggered. Release button within 3000ms to cancel.[0m

bzbarsky-apple commented 8 months ago

@solstice-gao So what is the actual issue? There is no summary for the issue and no clear description of the problem.

dhrishi commented 8 months ago

@solstice-gao This issue should be fixed with https://github.com/project-chip/connectedhomeip/pull/31500