- </s><e>
As title, I am troubling in commission with chip tool and iphone app.
Development environment:
* EVB: ESP32-H2-DEV-KIT-N4 / ESP32-H2-DevKitM-1 board
* router: ESP thread border router
* PC: MacPro Monterey and Ubuntu 22.04
* ESP-IDF: v5.1.2 (v5.1.3 and v5.2.1 test too)
* ESP-Matter: v1.2
* ESP-Thread-BR: v1.0 (main test too)
* iOS and Macos has installed profile as described on ESP-Matter github site.
* Use "Light" sample code w/o any modification
Test cases:
1. Use "ESP MATTER" app on iOS to add new device with common QR code, very very little case could connect, and even though not keepping work for long time. Also commission time takes long time (over 20~30 sec above).
2. Use "ESP Rainmaker"app on iOS to add new device with common QR code, it will warm up no border router exist. Question is how to enable my ESP thread border router in this case?
3. Start up thread border router, either by chip-tool or iphone app commission, result is same as case 1.
4. In order to bypass ESP32H2 image build environment issue, change to test by using launchpad default image. But result is same as prior three cases.
My chip-tool parameter is "pairing ble-thread 0x7283 hex:0e080000000000010000000300000f35060004001fffe00208dead00beef00cafe0708fd000db800a00000051000112233445566778899aabbccddeeff030e4f70656e5468726561642d455350010212340410104810e2315100afd6bc9215a6bfac530c0402a0f7f8 20202021 3840"
On ESP Matter app, default dataset and my BR dataset both have tested. Only my BR dataset will pass test.
When start to commission, initially show up connection message very fast. But after 5~10sec, it becomes pretty slow, finally looks like timeout and BLE connection close.
Below is ESP32H2 log messages:
==================================
ESP-ROM:esp32h2-20221101
Build:Nov 1 2022
rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x4083cfd0,len:0xcd4
load:0x4083efd0,len:0x2d9c
load:0x408460e8,len:0x1778
entry 0x4083cfd0
[0;32mI (23) boot: ESP-IDF 482a8fb 2nd stage bootloader[0m
[0;32mI (24) boot: compile time Apr 6 2024 13:21:11[0m
[0;32mI (25) boot: chip revision: v0.1[0m
[0;32mI (27) boot.esp32h2: SPI Speed : 64MHz[0m
[0;32mI (31) boot.esp32h2: SPI Mode : DIO[0m
[0;32mI (36) boot.esp32h2: SPI Flash Size : 4MB[0m
[0;32mI (41) boot: Enabling RNG early entropy source...[0m
[0;32mI (46) boot: Partition Table:[0m
[0;32mI (50) boot: ## Label Usage Type ST Offset Length[0m
[0;32mI (57) boot: 0 esp_secure_cert unknown 3f 06 0000d000 00002000[0m
[0;32mI (65) boot: 1 nvs WiFi data 01 02 00010000 0000c000[0m
[0;32mI (72) boot: 2 nvs_keys NVS keys 01 04 0001c000 00001000[0m
[0;32mI (79) boot: 3 otadata OTA data 01 00 0001d000 00002000[0m
[0;32mI (87) boot: 4 phy_init RF data 01 01 0001f000 00001000[0m
[0;32mI (94) boot: 5 ota_0 OTA app 00 10 00020000 001e0000[0m
[0;32mI (102) boot: 6 ota_1 OTA app 00 11 00200000 001e0000[0m
[0;32mI (109) boot: 7 fctry WiFi data 01 02 003e0000 00006000[0m
[0;32mI (117) boot: 8 coredump Unknown data 01 03 003e6000 00010000[0m
[0;32mI (125) boot: End of partition table[0m
[0;32mI (129) esp_image: segment 0: paddr=00020020 vaddr=42150020 size=3e210h (254480) map[0m
[0;32mI (215) esp_image: segment 1: paddr=0005e238 vaddr=40800000 size=01de0h ( 7648) load[0m
[0;32mI (219) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=142ed0h (1322704) map[0m
[0;32mI (627) esp_image: segment 3: paddr=001a2ef8 vaddr=40801de0 size=1128ch ( 70284) load[0m
[0;32mI (652) esp_image: segment 4: paddr=001b418c vaddr=40813070 size=03540h ( 13632) load[0m
[0;32mI (658) esp_image: segment 5: paddr=001b76d4 vaddr=50000000 size=00004h ( 4) load[0m
[0;32mI (664) boot: Loaded app from partition at offset 0x20000[0m
[0;32mI (665) boot: Disabling RNG early entropy source...[0m
[0;32mI (681) cpu_start: Unicore app[0m
[0;32mI (682) cpu_start: Pro cpu up.[0m
[0;33mW (690) clk: esp_perip_clk_init() has not been implemented yet[0m
[0;32mI (697) cpu_start: Pro cpu start user code[0m
[0;32mI (697) cpu_start: cpu freq: 96000000 Hz[0m
[0;32mI (698) cpu_start: Application information:[0m
[0;32mI (700) cpu_start: Project name: light[0m
[0;32mI (705) cpu_start: App version: 1.0[0m
[0;32mI (709) cpu_start: Compile time: Apr 6 2024 13:21:03[0m
[0;32mI (715) cpu_start: ELF file SHA256: 98def28684d4c6ee...[0m
[0;32mI (721) cpu_start: ESP-IDF: 482a8fb[0m
[0;32mI (726) cpu_start: Min chip rev: v0.0[0m
[0;32mI (731) cpu_start: Max chip rev: v0.99 [0m
[0;32mI (736) cpu_start: Chip rev: v0.1[0m
[0;32mI (741) heap_init: Initializing. RAM available for dynamic allocation:[0m
[0;32mI (748) heap_init: At 4082BC20 len 00021760 (133 KiB): D/IRAM[0m
[0;32mI (754) heap_init: At 4084D380 len 00002B60 (10 KiB): STACK/DIRAM[0m
[0;32mI (762) spi_flash: detected chip: generic[0m
[0;32mI (766) spi_flash: flash io: dio[0m
[0;32mI (771) sleep: Configure to isolate all GPIO pins in sleep state[0m
[0;32mI (777) sleep: Enable automatic switching of GPIO sleep configuration[0m
[0;32mI (783) esp_core_dump_flash: Init core dump to flash[0m
[0;32mI (790) esp_core_dump_flash: Found partition 'coredump' @ 3e6000 65536 bytes[0m
[0;32mI (797) coexist: coex firmware version: b6d5e8c[0m
[0;32mI (803) app_start: Starting scheduler on CPU0[0m
[0;32mI (807) main_task: Started on CPU0[0m
[0;32mI (807) main_task: Calling app_main()[0m
[0;32mI (827) led_indicator: LED Indicator Version: 0.9.2[0m
[0;33mW (827) rmt: channel resolution loss, real=10666666[0m
[0;32mI (837) gpio: GPIO[8]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 [0m
[0;32mI (837) led_indicator: Indicator create successfully. type:LED Strips mode, hardware_data:0x4084e354, blink_lists:custom[0m
[0;32mI (857) button: IoT Button Version: 3.2.0[0m
[0;32mI (857) gpio: GPIO[9]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 [0m
[0;32mI (877) app_main: Light created with endpoint_id 1[0m
[0;32mI (907) chip[DL]: NVS set: chip-counters/reboot-count = 15 (0xF)[0m
[0;32mI (907) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC)[0m
[0;32mI (907) BLE_INIT: Using main XTAL as clock source[0m
controller lib commit: [77d09ce]
[0;32mI (927) OPENTHREAD: Host connection mode none[0m
[0;32mI (927) phy: phy_version: 211,0, 5857fe5, Nov 1 2023, 11:31:09[0m
[0;32mI (927) phy: libbtbb version: ce629d6, Nov 1 2023, 11:31:19[0m
[0;32mI (947) NimBLE: GAP procedure initiated: stop advertising.
[0m
[0;32mI (947) NimBLE: Failed to restore IRKs from store; status=8
[0m
[0;32mI (947) CHIP[DL]: BLE host-controller synced[0m
[0;32mI (967) OPENTHREAD: OpenThread attached to netif[0m
[0;32mI(977) OPENTHREAD:[N] Mle-----------: Role disabled -> detached[0m
[0;32mI (997) chip[DL]: OpenThread ifconfig up and thread start[0m
[0;32mI (997) chip[DL]: OpenThread started: OK[0m
[0;32mI (997) chip[DL]: Setting OpenThread device type to ROUTER[0m
[0;32mI (1017) OT_STATE: netif up[0m
[0;31mE (1467) chip[DMG]: Endpoint 0, Cluster 0x0000_0031 not found in IncreaseClusterDataVersion![0m
[0;31mE (1477) chip[DMG]: Endpoint 0, Cluster 0x0000_0031 not found in IncreaseClusterDataVersion![0m
[0;31mE (1477) chip[DMG]: Endpoint 0, Cluster 0x0000_0031 not found in IncreaseClusterDataVersion![0m
[0;32mI (1487) chip[SVR]: Initializing subscription resumption storage...[0m
[0;32mI (1497) chip[SVR]: Server initializing...[0m
[0;32mI (1497) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48[0m
[0;32mI (1507) chip[DMG]: AccessControl: initializing[0m
[0;32mI (1507) chip[DMG]: Examples::AccessControlDelegate::Init[0m
[0;32mI (1517) chip[DMG]: AccessControl: setting[0m
[0;32mI (1527) chip[DMG]: DefaultAclStorage: initializing[0m
[0;32mI (1527) chip[DMG]: DefaultAclStorage: 0 entries loaded[0m
[0;32mI (1547) chip[ZCL]: Using ZAP configuration...[0m
[0;32mI (1547) esp_matter_cluster: Cluster plugin init common callback[0m
[0;32mI (1547) chip[DMG]: AccessControlCluster: initializing[0m
[0;32mI (1557) chip[ZCL]: 0x42157ca0 ep 0 clus 0x0000_0030 attr 0x0000_0000 not supported[0m
[0;32mI (1567) chip[ZCL]: Initiating Admin Commissioning cluster.[0m
[0;32mI (1577) chip[DIS]: Updating services using commissioning mode 1[0m
[0;31mE (1577) chip[DIS]: Failed to remove advertised services: 3[0m
[0;32mI (1587) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0[0m
[0;31mE (1597) chip[DIS]: Failed to advertise commissionable node: 3[0m
[0;31mE (1607) chip[DIS]: Failed to finalize service update: 3[0m
[0;32mI (1607) chip[IN]: CASE Server enabling CASE session setups[0m
[0;32mI (1617) chip[SVR]: Joining Multicast groups[0m
[0;32mI (1617) chip[SVR]: Server Listening...[0m
[0;32mI (1627) esp_matter_core: Dynamic endpoint 0 added[0m
[0;32mI (1627) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000003's Attribute 0x00000001 is 0 **********[0m
[0;32mI (1637) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x00000000 is 128 **********[0m
[0;32mI (1657) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x0000FFFC is <invalid type: 0> **********[0m
[0;32mI (1667) chip[ZCL]: 0x42157ca0 ep 1 clus 0x0000_0062 attr 0x0000_0000 not supported[0m
[0;32mI (1677) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000006's Attribute 0x0000FFFC is 1 **********[0m
[0;32mI (1687) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000006's Attribute 0x00004003 is null **********[0m
[0;32mI (1697) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000006's Attribute 0x00000000 is 0 **********[0m
[0;32mI (1707) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000006's Attribute 0x00000000 is 0 **********[0m
[0;32mI (1717) chip[ZCL]: Endpoint 1 On/off already set to new value[0m
[0;32mI (1727) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00000002 is 1 **********[0m
[0;32mI (1737) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00000003 is 254 **********[0m
[0;32mI (1747) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x0000FFFC is 3 **********[0m
[0;32mI (1767) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00000000 is 64 **********[0m
[0;32mI (1777) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00004000 is 64 **********[0m
[0;32mI (1787) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000008's Attribute 0x00000000 is 64 **********[0m
[0;32mI (1797) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000300's Attribute 0x00004010 is null **********[0m
[0;32mI (1807) esp_matter_core: Dynamic endpoint 1 added[0m
[0;32mI (1817) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)[0m
[0;32mI (1827) NimBLE: GAP procedure initiated: advertise; [0m
[0;32mI (1827) NimBLE: disc_mode=2[0m
[0;32mI (1837) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40[0m
[0;32mI (1847) NimBLE:
[0m
[0;32mI (1847) chip[DL]: CHIPoBLE advertising started[0m
[0;32mI (1857) app_main: Commissioning window opened[0m
[5n[0;32m> [0m[0;32mI (2367) main_task: Returned from app_main()[0m
[0;32mI (4797) esp_matter_core: Store the deferred attribute 0x0 of cluster 0x8 on endpoint 0x1[0m
[0;32mI(27647) OPENTHREAD:[N] Mle-----------: RLOC16 9c00 -> fffe[0m
[0;32mI(27797) OPENTHREAD:[N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset[0m
[0;32mI (31577) chip[DL]: Configuring CHIPoBLE advertising (interval 500 ms, connectable)[0m
[0;32mI (31577) chip[DL]: Device already advertising, stop active advertisement and restart[0m
[0;32mI (31587) NimBLE: GAP procedure initiated: stop advertising.
[0m
[0;32mI (31597) NimBLE: GAP procedure initiated: advertise; [0m
[0;32mI (31607) NimBLE: disc_mode=2[0m
[0;32mI (31607) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=800 adv_itvl_max=800[0m
[0;32mI (31617) NimBLE:
[0m
[0;32mI(34367) OPENTHREAD:[N] RouterTable---: Allocate router id 39[0m
[0;32mI(34377) OPENTHREAD:[N] Mle-----------: RLOC16 fffe -> 9c00[0m
[0;32mI(34377) OPENTHREAD:[N] Mle-----------: Role detached -> leader[0m
[0;32mI(34377) OPENTHREAD:[N] Mle-----------: Partition ID 0x706476d[0m
[0;32m> [0m[0;32mI (96827) chip[DL]: BLE GAP connection established (con 1)[0m
[0;32mI (96837) chip[DL]: CHIPoBLE advertising stopped[0m
[0;32mI (98127) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (98127) chip[BLE]: local and remote recv window sizes = 5[0m
[0;32mI (98137) chip[BLE]: selected BTP version 4[0m
[0;32mI (98147) chip[BLE]: using BTP fragment sizes rx 244 / tx 244.[0m
[0;32mI (98217) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 1[0m
[0;32mI (98217) chip[DL]: CHIPoBLE subscribe received[0m
[0;32mI (98217) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (98237) NimBLE: att_handle=14
[0m
[0;32mI (98307) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (98317) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (98327) chip[EM]: >>> [E:36867r S:0 M:63458796] (U) Msg RX from 0:A65E601900A88E31 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)[0m
[0;32mI (98347) chip[EM]: <<< [E:36867r S:0 M:200569201] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)[0m
[0;32mI (98357) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (98357) NimBLE: att_handle=14
[0m
[0;32mI (98357) chip[SVR]: Commissioning session establishment step started[0m
[0;32mI (98447) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (98447) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (98457) chip[EM]: >>> [E:36867r S:0 M:63458797] (U) Msg RX from 0:A65E601900A88E31 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)[0m
[0;32mI (98577) chip[EM]: <<< [E:36867r S:0 M:200569202] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2)[0m
[0;32mI (98577) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (98587) NimBLE: att_handle=14
[0m
[0;32mI (98667) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (98667) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (98687) chip[EM]: >>> [E:36867r S:0 M:63458798] (U) Msg RX from 0:A65E601900A88E31 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)[0m
[0;32mI (98697) chip[EM]: <<< [E:36867r S:0 M:200569203] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport)[0m
[0;32mI (98707) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (98717) NimBLE: att_handle=14
[0m
[0;32mI (98717) chip[SC]: SecureSession[0x40819b78, LSID:52146]: State change 'kEstablishing' --> 'kActive'[0m
[0;32mI (98737) chip[SVR]: Commissioning completed session establishment step[0m
[0;32mI (98737) chip[DIS]: Updating services using commissioning mode 0[0m
[0;31mE (98747) chip[DIS]: Failed to remove advertised services: 3[0m
[0;32mI (98747) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=0 cp=0[0m
[0;31mE (98757) chip[DIS]: Failed to advertise extended commissionable node: 3[0m
[0;31mE (98767) chip[DIS]: Failed to finalize service update: 3[0m
[0;32mI (98777) chip[SVR]: Device completed Rendezvous process[0m
[0;32mI (98777) app_main: Commissioning session started[0m
[0;32mI (98787) app_main: Commissioning window closed[0m
[0;32mI (98807) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (98807) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (98827) chip[EM]: >>> [E:36868r S:52146 M:141445189] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)[0m
[0;32mI (98827) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 **********[0m
[0;32mI (98847) chip[EM]: <<< [E:36868r S:52146 M:207018856] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)[0m
[0;32mI (98857) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (98867) NimBLE: att_handle=14
[0m
[0;32mI (98937) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (98937) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (98957) NimBLE: att_handle=14
[0m
[0;32mI (99027) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99037) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (99047) chip[EM]: >>> [E:36869r S:52146 M:141445190] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)[0m
[0;32mI (99057) chip[EM]: <<< [E:36869r S:52146 M:207018857] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)[0m
[0;32mI (99067) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99067) NimBLE: att_handle=14
[0m
[0;32mI (99167) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99167) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (99177) chip[EM]: >>> [E:36870r S:52146 M:141445191] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (99187) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x00000030[0m
[0;32mI (99197) chip[FS]: GeneralCommissioning: Received ArmFailSafe (60s)[0m
[0;32mI (99207) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 4 **********[0m
[0;32mI (99217) chip[EM]: <<< [E:36870r S:52146 M:207018858] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (99227) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99247) NimBLE: att_handle=14
[0m
[0;32mI (99297) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99307) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (99317) chip[EM]: >>> [E:36871r S:52146 M:141445192] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (99327) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x00000030[0m
[0;32mI (99337) chip[DL]: NVS set: chip-config/reg-location = 0 (0x0)[0m
[0;32mI (99347) chip[DL]: NVS set: chip-config/country-code = "XX"[0m
[0;32mI (99347) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 5 **********[0m
[0;32mI (99367) chip[EM]: <<< [E:36871r S:52146 M:207018859] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (99377) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99377) NimBLE: att_handle=14
[0m
[0;32mI (99437) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99437) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (99447) chip[EM]: >>> [E:36872r S:52146 M:141445193] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (99457) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x0000003E[0m
[0;32mI (99467) chip[ZCL]: OpCreds: Certificate Chain request received for PAI[0m
[0;32mI (99487) chip[EM]: <<< [E:36872r S:52146 M:207018860] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (99497) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99497) NimBLE: att_handle=14
[0m
[0;32mI (99567) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99567) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99587) NimBLE: att_handle=14
[0m
[0;32mI (99657) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99657) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99677) NimBLE: att_handle=14
[0m
[0;32mI (99747) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99757) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (99767) chip[EM]: >>> [E:36873r S:52146 M:141445194] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (99767) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x0000003E[0m
[0;32mI (99787) chip[ZCL]: OpCreds: Certificate Chain request received for DAC[0m
[0;32mI (99797) chip[EM]: <<< [E:36873r S:52146 M:207018861] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (99817) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99817) NimBLE: att_handle=14
[0m
[0;32mI (99887) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99887) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99897) NimBLE: att_handle=14
[0m
[0;32mI (99977) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (99977) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (99987) NimBLE: att_handle=14
[0m
[0;32mI (100067) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (100067) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (100087) chip[EM]: >>> [E:36874r S:52146 M:141445195] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (100087) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x0000003E[0m
[0;32mI (100097) chip[ZCL]: OpCreds: Received an AttestationRequest command[0m
[0;32mI (100137) chip[ZCL]: OpCreds: AttestationRequest successful.[0m
[0;32mI (100147) chip[EM]: <<< [E:36874r S:52146 M:207018862] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (100157) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (100167) NimBLE: att_handle=14
[0m
[0;32mI (100247) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (100247) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (100257) NimBLE: att_handle=14
[0m
[0;32mI (100337) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (100337) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (100347) NimBLE: att_handle=14
[0m
[0;32mI (100427) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (100427) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (100447) chip[EM]: >>> [E:36875r S:52146 M:141445196] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (100447) esp_matter_command: Received command 0x00000004 for endpoint 0x0000's cluster 0x0000003E[0m
[0;32mI (100457) chip[ZCL]: OpCreds: Received a CSRRequest command[0m
[0;32mI (100517) chip[ZCL]: OpCreds: AllocatePendingOperationalKey succeeded[0m
[0;32mI (100547) chip[ZCL]: OpCreds: CSRRequest successful.[0m
[0;32mI (100557) chip[EM]: <<< [E:36875r S:52146 M:207018863] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (100557) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (100567) NimBLE: att_handle=14
[0m
[0;32mI (100647) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (100647) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (100667) NimBLE: att_handle=14
[0m
[0;32mI (100737) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (100747) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (100827) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (100837) chip[EM]: >>> [E:36876r S:52146 M:141445197] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (100847) esp_matter_command: Received command 0x0000000B for endpoint 0x0000's cluster 0x0000003E[0m
[0;32mI (100857) chip[ZCL]: OpCreds: Received an AddTrustedRootCertificate command[0m
[0;32mI (100897) chip[ZCL]: OpCreds: AddTrustedRootCertificate successful.[0m
[0;32mI (100907) chip[EM]: <<< [E:36876r S:52146 M:207018864] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (100917) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (100917) NimBLE: att_handle=14
[0m
[0;32mI (101007) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (101017) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (101097) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (101187) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (101197) chip[EM]: >>> [E:36877r S:52146 M:141445198] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (101207) esp_matter_command: Received command 0x00000006 for endpoint 0x0000's cluster 0x0000003E[0m
[0;32mI (101217) chip[ZCL]: OpCreds: Received an AddNOC command[0m
[0;32mI (101227) chip[FP]: Validating NOC chain[0m
[0;32mI (101297) chip[FP]: NOC chain validation successful[0m
[0;32mI (101297) chip[FP]: Added new fabric at index: 0x1[0m
[0;32mI (101297) chip[FP]: Assigned compressed fabric ID: 0x5C55E8EA64A00B3A, node ID: 0x0000000000007283[0m
[0;32mI (101307) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48[0m
[0;32mI (101327) chip[TS]: New proposed Last Known Good Time: 2021-01-01T00:00:00[0m
[0;32mI (101327) chip[TS]: Retaining current Last Known Good Time[0m
[0;32mI (101347) chip[ZCL]: OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669[0m
[0;32mI (101347) chip[DIS]: Advertise operational node 5C55E8EA64A00B3A-0000000000007283[0m
[0;32mI (101367) chip[ZCL]: OpCreds: successfully created fabric index 0x1 via AddNOC[0m
[0;32mI (101367) chip[EM]: <<< [E:36877r S:52146 M:207018865] (S) Msg TX to 1:FFFFFFFB00000000 [0B3A] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (101387) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (101397) NimBLE: att_handle=14
[0m
[0;32mI (101397) app_main: Fabric is updated[0m
[0;32mI (101457) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (101467) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (101477) chip[EM]: >>> [E:36878r S:52146 M:141445199] (S) Msg RX from 1:FFFFFFFB00000000 [0B3A] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (101487) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 24 **********[0m
[0;32mI (101497) chip[EM]: <<< [E:36878r S:52146 M:207018866] (S) Msg TX to 1:FFFFFFFB00000000 [0B3A] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (101517) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (101517) NimBLE: att_handle=14
[0m
[0;32mI (101597) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (101597) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (101607) chip[EM]: >>> [E:36879r S:52146 M:141445200] (S) Msg RX from 1:FFFFFFFB00000000 [0B3A] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI (101627) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x00000030[0m
[0;32mI (101627) chip[FS]: GeneralCommissioning: Received ArmFailSafe (73s)[0m
[0;32mI (101637) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 26 **********[0m
[0;32mI (101657) chip[EM]: <<< [E:36879r S:52146 M:207018867] (S) Msg TX to 1:FFFFFFFB00000000 [0B3A] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (101667) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (101677) NimBLE: att_handle=14
[0m
[0;32mI (101727) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (101737) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (101747) chip[EM]: >>> [E:36880r S:52146 M:141445201] (S) Msg RX from 1:FFFFFFFB00000000 [0B3A] --- Type 0001:08 (IM:InvokeCommandRequest)[0m
[0;32mI(101767) OPENTHREAD:[N] Mle-----------: Role leader -> detached[0m
[0;32mI(101767) OPENTHREAD:[N] Mle-----------: Role detached -> disabled[0m
[0;32mI(101777) OPENTHREAD:[N] Mle-----------: Role disabled -> detached[0m
[0;32mI (101787) chip[DL]: Updating advertising data[0m
[0;31mE (101787) OPENTHREAD: Failed to send to Thread netif: packet queue full[0m
[0;31mE (101797) OPENTHREAD: Failed to send to Thread netif: packet queue full[0m
[0;32mI (101817) OT_STATE: netif up[0m
[0;32mI (104247) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (104247) NimBLE: att_handle=14
[0m
[0;32mI (104427) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (107037) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (109537) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (109547) NimBLE: att_handle=14
[0m
[0;32mI (109697) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (112307) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (114807) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (114807) NimBLE: att_handle=14
[0m
[0;32mI (114957) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (117567) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (120067) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (120077) NimBLE: att_handle=14
[0m
[0;32mI (120227) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (122837) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (125337) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (125337) NimBLE: att_handle=14
[0m
[0;32mI (125487) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI(127327) OPENTHREAD:[N] Mle-----------: RLOC16 9c00 -> fffe[0m
[0;32mI(128077) OPENTHREAD:[N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset[0m
[0;32mI (128097) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (130607) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (130607) NimBLE: att_handle=14
[0m
[0;32mI (130757) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (133367) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI(134647) OPENTHREAD:[N] RouterTable---: Allocate router id 39[0m
[0;32mI(134657) OPENTHREAD:[N] Mle-----------: RLOC16 fffe -> 9c00[0m
[0;32mI(134657) OPENTHREAD:[N] Mle-----------: Role detached -> leader[0m
[0;32mI(134657) OPENTHREAD:[N] Mle-----------: Partition ID 0x37afdba8[0m
[0;32mI (134707) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 28 **********[0m
[0;32mI (134717) chip[EM]: <<< [E:36880r S:52146 M:207018868] (S) Msg TX to 1:FFFFFFFB00000000 [0B3A] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)[0m
[0;32mI (134727) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (134737) NimBLE: att_handle=14
[0m
[0;32mI (134737) chip[DIS]: Advertise operational node 5C55E8EA64A00B3A-0000000000007283[0m
[0;32mI (134747) chip[SVR]: Operational advertising enabled[0m
[0;32mI (134807) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (137417) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (139917) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (139917) NimBLE: att_handle=14
[0m
[0;32mI (140067) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (142677) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (145187) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (145187) NimBLE: att_handle=14
[0m
[0;32mI (145337) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (147947) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (150447) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (150447) NimBLE: att_handle=14
[0m
[0;32mI (150597) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (153207) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (155717) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (155717) NimBLE: att_handle=14
[0m
[0;32mI (155867) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (158477) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (160977) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (160977) NimBLE: att_handle=14
[0m
[0;32mI (161127) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (163737) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (166247) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (166247) NimBLE: att_handle=14
[0m
[0;32mI (166437) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (169047) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (171557) NimBLE: GATT procedure initiated: indicate; [0m
[0;32mI (171557) NimBLE: att_handle=14
[0m
[0;32mI (171707) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14 [0m
[0;32mI (174317) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (174647) chip[FS]: Fail-safe timer expired[0m
[0;31mE (174647) chip[SVR]: Failsafe timer expired[0m
[0;32mI (174647) chip[SC]: SecureSession[0x40819b78, LSID:52146]: State change 'kActive' --> 'kPendingEviction'[0m
[0;31mE (174657) chip[SVR]: Commissioning failed (attempt 1): 32[0m
[0;32mI (174657) chip[BLE]: Releasing end point's BLE connection back to application.[0m
[0;32mI (174677) chip[DIS]: Updating services using commissioning mode 1[0m
[0;31mE (174677) chip[DIS]: Failed to remove advertised services: 3[0m
[0;32mI (174687) chip[DIS]: Advertise operational node 5C55E8EA64A00B3A-0000000000007283[0m
[0;31mE (174687) chip[DIS]: Failed to advertise operational node: 3[0m
[0;32mI (174697) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0[0m
[0;31mE (174717) chip[DIS]: Failed to advertise commissionable node: 3[0m
[0;31mE (174717) chip[DIS]: Failed to finalize service update: 3[0m
[0;31mE (174727) chip[ZCL]: OpCreds: Got FailSafeTimerExpired[0m
[0;31mE (174727) chip[ZCL]: OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry![0m
[0;31mE (174737) chip[FP]: Reverting pending fabric data for fabric 0x1[0m
[0;31mE (174747) chip[FP]: Warning: metadata not found during delete of fabric 0x1[0m
[0;32mI (174757) chip[FP]: Fabric (0x1) deleted.[0m
[0;32mI (174767) chip[ZCL]: OpCreds: Fabric index 0x1 was removed[0m
[0;32mI (174767) chip[DIS]: Updating services using commissioning mode 1[0m
[0;31mE (174777) chip[DIS]: Failed to remove advertised services: 3[0m
[0;32mI (174777) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0[0m
[0;31mE (174787) chip[DIS]: Failed to advertise commissionable node: 3[0m
[0;31mE (174797) chip[DIS]: Failed to finalize service update: 3[0m
[0;32mI (174847) chip[TS]: Pending Last Known Good Time: 2023-10-14T01:16:48[0m
[0;32mI (174847) chip[TS]: Previous Last Known Good Time: 2023-10-14T01:16:48[0m
[0;32mI (174857) chip[TS]: Reverted Last Known Good Time to previous value[0m
[0;31mE (174867) chip[FP]: Warning: metadata not found during delete of fabric 0x1[0m
[0;31mE (174877) chip[ZCL]: OpCreds: failed to delete fabric at index 1: d8[0m
[0;32mI (174877) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 **********[0m
[0;32mI (174887) chip[NP]: Reverting Thread operational dataset[0m
[0;32mI(174907) OPENTHREAD:[N] Mle-----------: Role leader -> detached[0m
[0;32mI(174907) OPENTHREAD:[N] Mle-----------: Role detached -> disabled[0m
[0;32mI(174917) OPENTHREAD:[N] Mle-----------: Role disabled -> detached[0m
[0;31mE (174927) OPENTHREAD: Failed to send to Thread netif: packet queue full[0m
[0;31mE (174927) OPENTHREAD: Failed to send to Thread netif: packet queue full[0m
[0;32mI (174937) app_main: Commissioning failed, fail safe timer expired[0m
[0;32mI (174947) chip[FS]: Fail-safe cleanly disarmed[0m
[0;32mI (174947) app_main: Commissioning window opened[0m
[0;32mI (174957) app_main: Fabric will be removed[0m
[0;32mI (174957) app_main: Fabric removed successfully[0m
[0;32mI (174967) app_main: Fabric will be removed[0m
[0;32mI (174967) chip[DL]: Updating advertising data[0m
[0;32mI (174957) OT_STATE: netif up[0m
[0;32mI (179897) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 1 12[0m
[0;32mI (179897) chip[BLE]: Releasing end point's BLE connection back to application.[0m
[0;31mE (179907) chip[BLE]: HandleChipConnectionReceived failed, err = 417[0m
[0;31mE (179907) chip[BLE]: failed handle new chip BLE connection, status = 417[0m
[0;32mI (189297) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 0[0m
[0;32mI (189297) chip[DL]: CHIPoBLE unsubscribe received[0m
[0;31mE (189307) chip[BLE]: no endpoint for unsub recvd[0m
[0;32mI (189317) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)[0m
[0;32mI (189327) NimBLE: GAP procedure initiated: advertise; [0m
[0;32mI (189327) NimBLE: disc_mode=2[0m
[0;32mI (189327) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40[0m
[0;32mI (189347) NimBLE:
[0m
[0;32mI (189347) chip[DL]: CHIPoBLE advertising started[0m
[0;32mI (191417) chip[DL]: BLE GAP connection terminated (con 1 reason 0x213)[0m
[0;32mI (191417) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)[0m
[0;32mI (191417) chip[DL]: Device already advertising, stop active advertisement and restart[0m
[0;32mI (191427) NimBLE: GAP procedure initiated: stop advertising.
[0m
[0;32mI (191447) NimBLE: GAP procedure initiated: advertise; [0m
[0;32mI (191447) NimBLE: disc_mode=2[0m
[0;32mI (191447) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40[0m
[0;32mI (191457) NimBLE:
[0m
[0;32mI (191457) esp_matter_core: BLE Disconnected[0m
[0;32mI(202227) OPENTHREAD:[N] Mle-----------: RLOC16 9c00 -> fffe[0m
[0;32mI(202547) OPENTHREAD:[N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset[0m
[0;32mI (204677) chip[DL]: Configuring CHIPoBLE advertising (interval 500 ms, connectable)[0m
[0;32mI (204677) chip[DL]: Device already advertising, stop active advertisement and restart[0m
[0;32mI (204687) NimBLE: GAP procedure initiated: stop advertising.
[0m
[0;32mI (204687) NimBLE: GAP procedure initiated: advertise; [0m
[0;32mI (204707) NimBLE: disc_mode=2[0m
[0;32mI (204707) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=800 adv_itvl_max=800[0m
[0;32mI (204717) NimBLE:
[0m
[0;32mI(209117) OPENTHREAD:[N] RouterTable---: Allocate router id 39[0m
[0;32mI(209127) OPENTHREAD:[N] Mle-----------: RLOC16 fffe -> 9c00[0m
[0;32mI(209127) OPENTHREAD:[N] Mle-----------: Role detached -> leader[0m
[0;32mI(209127) OPENTHREAD:[N] Mle-----------: Partition ID 0x2202d138[0m
==================================
Could anyone help to clarify why commission always fail ?