Closed nichonaugle closed 1 year ago
shubhamdp
commented
1 year ago @nichonaugle I do not see this error in your logs.
Also, this error is supposed to show up on the very first boot as there won't be a namespace present and device tries to read that. You will not see this error on subsequent boot as there will be a valid namespace present and it is readable at that time.
nichonaugle
commented
1 year ago @nichonaugle I do not see this error in your logs.
Also, this error is supposed to show up on the very first boot as there won't be a namespace present and device tries to read that. You will not see this error on subsequent boot as there will be a valid namespace present and it is readable at that time.
The error is during commissioning via the esp matter app on iPhone. It immediately terminates the connection whenever I scan the QR Code and then proceeds to turn the commissioning beacon back on. This is seen at the end of the logs. It doesn't matter how many times I try it does this over and over. I have also tried to download using esp-launchpad and the same error still occurred
dhrishi
commented
1 year ago @nichonaugle I am closing the original issue as it is answered. If you are facing any problems during commissioning, please create a new issue and upload (and not paste) the logs on both the device and the chip-tool side. Also, please provide all the necessary versions/GIT tags or commits for esp-matter and esp-idf
Whenever I attempt to commision the "light" example which was installed on esp32c3 i get the following:
I (30) boot: ESP-IDF v5.0.1 2nd stage bootloader I (30) boot: compile time 01:28:10 I (30) boot: chip revision: v0.3 I (32) boot.esp32c3: SPI Speed : 80MHz I (37) boot.esp32c3: SPI Mode : DIO I (42) boot.esp32c3: SPI Flash Size : 4MB I (46) boot: Enabling RNG early entropy source... I (52) boot: Partition Table: I (55) boot: ## Label Usage Type ST Offset Length I (63) boot: 0 esp_secure_cert unknown 3f 06 0000d000 00002000 I (70) boot: 1 nvs WiFi data 01 02 00010000 00006000 I (78) boot: 2 nvs_keys NVS keys 01 04 00016000 00001000 I (85) boot: 3 otadata OTA data 01 00 00017000 00002000 I (93) boot: 4 phy_init RF data 01 01 00019000 00001000 I (100) boot: 5 ota_0 OTA app 00 10 00020000 001e0000 I (108) boot: 6 ota_1 OTA app 00 11 00200000 001e0000 I (115) boot: 7 fctry WiFi data 01 02 003e0000 00006000 I (123) boot: End of partition table I (127) esp_image: segment 0: paddr=00020020 vaddr=3c100020 size=37268h (225896) map I (169) esp_image: segment 1: paddr=00057290 vaddr=3fc94200 size=03164h ( 12644) load I (172) esp_image: segment 2: paddr=0005a3fc vaddr=40380000 size=05c1ch ( 23580) load I (179) esp_image: segment 3: paddr=00060020 vaddr=42000020 size=feab0h (1043120) map I (340) esp_image: segment 4: paddr=0015ead8 vaddr=40385c1c size=0e4f8h ( 58616) load I (357) boot: Loaded app from partition at offset 0x20000 I (357) boot: Disabling RNG early entropy source... I (369) cpu_start: Pro cpu up. I (378) cpu_start: Pro cpu start user code I (378) cpu_start: cpu freq: 160000000 Hz I (378) cpu_start: Application information: I (381) cpu_start: Project name: light I (386) cpu_start: App version: v1.0 I (390) cpu_start: Compile time: May 22 2023 01:27:50 I (396) cpu_start: ELF file SHA256: 013690b508f08d80... I (402) cpu_start: ESP-IDF: v5.0.1 I (407) cpu_start: Min chip rev: v0.3 I (412) cpu_start: Max chip rev: v0.99 I (417) cpu_start: Chip rev: v0.3 I (422) heap_init: Initializing. RAM available for dynamic allocation: I (429) heap_init: At 3FCA8C30 len 00033AE0 (206 KiB): DRAM I (435) heap_init: At 3FCDC710 len 00002950 (10 KiB): STACK/DRAM I (442) heap_init: At 50000020 len 00001FE0 (7 KiB): RTCRAM I (449) spi_flash: detected chip: generic I (453) spi_flash: flash io: dio W (457) rmt(legacy): legacy driver is deprecated, please migrate to
driver/rmt_tx.hand/ordriver/rmt_rx.hI (468) coexist: coexist rom version 9387209 I (473) cpu_start: Starting scheduler. I (486) led_driver_ws2812: Initializing light driver I (496) gpio: GPIO[9]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 W (506) esp_matter_core: Command 0x00000047 on cluster 0x00000300 already exists. Not creating again. I (506) app_main: Light created with endpoint_id 1 I (516) pp: pp rom version: 9387209 I (516) net80211: net80211 rom version: 9387209 I (526) wifi:wifi driver task: 3fcb4804, prio:23, stack:6656, core=0 I (526) system_api: Base MAC address is not set I (536) system_api: read default base MAC address from EFUSE I (536) wifi:wifi firmware version: 17afb16 I (546) wifi:wifi certification version: v7.0 I (546) wifi:config NVS flash: enabled I (546) wifi:config nano formating: disabled I (556) wifi:Init data frame dynamic rx buffer num: 32 I (556) wifi:Init management frame dynamic rx buffer num: 32 I (566) wifi:Init management short buffer num: 32 I (566) wifi:Init dynamic tx buffer num: 32 I (576) wifi:Init static tx FG buffer num: 2 I (576) wifi:Init static rx buffer size: 1600 I (576) wifi:Init static rx buffer num: 10 I (586) wifi:Init dynamic rx buffer num: 32 I (586) wifi_init: rx ba win: 6 I (596) wifi_init: tcpip mbox: 32 I (596) wifi_init: udp mbox: 6 I (596) wifi_init: tcp mbox: 6 I (606) wifi_init: tcp tx win: 5744 I (606) wifi_init: tcp rx win: 5744 I (616) wifi_init: tcp mss: 1440 I (616) wifi_init: WiFi IRAM OP enabled I (616) wifi_init: WiFi RX IRAM OP enabled I (636) chip[DL]: NVS set: chip-counters/reboot-count = 3 (0x3) I (636) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC) I (636) BTDM_INIT: BT controller compile version [80abacd] I (646) phy_init: phy_version 950,11a46e9,Oct 21 2022,08:56:12 I (686) BTDM_INIT: Bluetooth MAC: 10:91:a8:3b:7e:eeI (686) NimBLE: GAP procedure initiated: stop advertising.
I (686) CHIP[DL]: BLE host-controller synced I (1186) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable) I (1186) NimBLE: GAP procedure initiated: advertise; I (1186) NimBLE: disc_mode=2 I (1186) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (1196) NimBLE:
I (1206) chip[DL]: CHIPoBLE advertising started I (1206) chip[DL]: Starting ESP WiFi layer I (1216) wifi:mode : sta (10:91:a8:3b:7e:ec) I (1216) wifi:enable tsf W (1216) wifi:Haven't to connect to a suitable AP now! I (1226) chip[DL]: Done driving station state, nothing else to do... W (1226) wifi:Haven't to connect to a suitable AP now! I (1236) chip[DL]: Done driving station state, nothing else to do... I (1246) chip[SVR]: Initializing subscription resumption storage... I (1246) chip[SVR]: Server initializing... I (1256) chip[TS]: Last Known Good Time: 2023-05-22T01:36:55 I (1256) chip[DMG]: AccessControl: initializing I (1266) chip[DMG]: Examples::AccessControlDelegate::Init I (1266) chip[DMG]: AccessControl: setting I (1276) chip[DMG]: DefaultAclStorage: initializing I (1286) chip[DMG]: DefaultAclStorage: 0 entries loaded I (1296) chip[ZCL]: Using ZAP configuration... I (1296) esp_matter_cluster: Cluster plugin init common callback I (1296) chip[DMG]: AccessControlCluster: initializing I (1306) chip[ZCL]: 0x3c109810ep 0 clus 0x0000_0030 attr 0x0000_0000 not supported I (1316) chip[ZCL]: Initiating Admin Commissioning cluster. E (1316) chip[ZCL]: Duplicate attribute override registration failed I (1326) chip[DIS]: Updating services using commissioning mode 1 I (1336) chip[DIS]: CHIP minimal mDNS started advertising. I (1336) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 I (1346) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: A14FDA4CA688E3A9. I (1356) chip[DIS]: mDNS service published: _matterc._udp I (1366) chip[IN]: CASE Server enabling CASE session setups I (1376) chip[SVR]: Joining Multicast groups I (1376) chip[SVR]: Server Listening... I (1386) esp_matter_core: Dynamic endpoint 0 added I (1386) esp_matter_attribute: ** W : Endpoint 0x0001's Cluster 0x00000003's Attribute 0x00000001 is 0 ** I (1396) esp_matter_attribute: ** W : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x00000000 is 128 ** I (1416) esp_matter_attribute: ** W : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x0000FFFC is <invalid type: 0> ** I (1426) esp_matter_attribute: ** W : Endpoint 0x0001's Cluster 0x00000005's Attribute 0x00000000 is 0 ** I (1436) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000006's Attribute 0x0000FFFC is 1 ** I (1446) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000006's Attribute 0x00004003 is null ** I (1456) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000006's Attribute 0x00000000 is 1 ** I (1476) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000006's Attribute 0x00000000 is 1 ** I (1486) chip[ZCL]: Endpoint 1 On/off already set to new value I (1486) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00000002 is 1 ** I (1496) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00000003 is 254 ** I (1516) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x0000FFFC is 3 ** I (1526) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00000000 is 64 ** I (1536) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00004000 is 64 ** I (1546) esp_matter_attribute: ** W : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00000000 is 64 ** I (1556) led_driver_ws2812: led set r:0, g:0, b:0 I (1566) esp_matter_attribute: ** R : Endpoint 0x0001's Cluster 0x00000300's Attribute 0x00004010 is null ** I (1576) esp_matter_core: Dynamic endpoint 1 added I (1586) chip[DL]: WIFI_EVENT_STA_START W (1586) wifi:Haven't to connect to a suitable AP now! I (1596) chip[DL]: Done driving station state, nothing else to do... I (1596) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable) I (1606) chip[DL]: Device already advertising, stop active advertisement and restart I (1616) NimBLE: GAP procedure initiated: stop advertising.
I (1626) NimBLE: GAP procedure initiated: advertise; I (1626) NimBLE: disc_mode=2 I (1626) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (1636) NimBLE:
I (1646) app_main: Commissioning window opened I (1646) led_driver_ws2812: led set r:0, g:0, b:0 I (1656) led_driver_ws2812: led set r:0, g:0, b:0 I (1656) led_driver_ws2812: led set r:63, g:51, b:40
I (16016) chip[DL]: CHIPoBLE advertising started I (31326) chip[DL]: Configuring CHIPoBLE advertising (interval 500 ms, connectable) I (31326) chip[DL]: Device already advertising, stop active advertisement and restart I (31346) NimBLE: GAP procedure initiated: stop advertising.
I (31346) NimBLE: GAP procedure initiated: advertise; I (31356) NimBLE: disc_mode=2 I (31356) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=800 adv_itvl_max=800 I (31366) NimBLE:
The main issues I see are that there is a duplicate attribute however I do not know if this issue is due to the software. I have tried to upload the sketch onto other esp32c3 as well as two esp32c6 which still did not work. When commissioning, it says commissioning window is open and then is immediately closed whenever I try and commission using the QR code.