giang@giang-ubuntu:~$ source ~/project/esp-idf-v5.3.2/export.sh Setting IDF_PATH to '/home/giang/project/esp-idf-v5.3.2' Detecting the Python interpreter Checking "python3" ... Python 3.12.3 "python3" has been detected Checking Python compatibility Checking other ESP-IDF version. Adding ESP-IDF tools to PATH... Checking if Python packages are up to date... Constraint file: /home/giang/.espressif/espidf.constraints.v5.3.txt Requirement files: - /home/giang/project/esp-idf-v5.3.2/tools/requirements/requirements.core.txt Python being checked: /home/giang/.espressif/python_env/idf5.3_py3.12_env/bin/python Python requirements are satisfied. Added the following directories to PATH: /home/giang/project/esp-idf-v5.3.2/components/espcoredump /home/giang/project/esp-idf-v5.3.2/components/partition_table /home/giang/project/esp-idf-v5.3.2/components/app_update /home/giang/.espressif/tools/xtensa-esp-elf-gdb/14.2_20240403/xtensa-esp-elf-gdb/bin /home/giang/.espressif/tools/riscv32-esp-elf-gdb/14.2_20240403/riscv32-esp-elf-gdb/bin /home/giang/.espressif/tools/xtensa-esp-elf/esp-13.2.0_20240530/xtensa-esp-elf/bin /home/giang/.espressif/tools/riscv32-esp-elf/esp-13.2.0_20240530/riscv32-esp-elf/bin /home/giang/.espressif/tools/esp32ulp-elf/2.38_20240113/esp32ulp-elf/bin /home/giang/.espressif/tools/openocd-esp32/v0.12.0-esp32-20241016/openocd-esp32/bin /home/giang/.espressif/tools/xtensa-esp-elf-gdb/14.2_20240403/xtensa-esp-elf-gdb/bin /home/giang/.espressif/tools/riscv32-esp-elf-gdb/14.2_20240403/riscv32-esp-elf-gdb/bin /home/giang/.espressif/tools/xtensa-esp-elf/esp-13.2.0_20240530/xtensa-esp-elf/bin /home/giang/.espressif/tools/riscv32-esp-elf/esp-13.2.0_20240530/riscv32-esp-elf/bin /home/giang/.espressif/tools/esp32ulp-elf/2.38_20240113/esp32ulp-elf/bin /home/giang/.espressif/tools/openocd-esp32/v0.12.0-esp32-20241016/openocd-esp32/bin /home/giang/.espressif/python_env/idf5.3_py3.12_env/bin /home/giang/project/esp-idf-v5.3.2/tools Done! You can now compile ESP-IDF projects. Go to the project directory and run: idf.py build giang@giang-ubuntu:~$ source ~/project/esp-matter/export.sh Setting ESP_MATTER_PATH to '/home/giang/project/esp-matter' giang@giang-ubuntu:~$ cd project/esp-matter/examples/light_switch/ giang@giang-ubuntu:~/project/esp-matter/examples/light_switch$ idf.py -p /dev/ttyACM1 monitor Executing action: monitor Running idf_monitor in directory /home/giang/project/esp-matter/examples/light_switch Executing "/home/giang/.espressif/python_env/idf5.3_py3.12_env/bin/python /home/giang/project/esp-idf-v5.3.2/tools/idf_monitor.py -p /dev/ttyACM1 -b 115200 --toolchain-prefix riscv32-esp-elf- --target esp32c6 --revision 0 --decode-panic backtrace /home/giang/project/esp-matter/examples/light_switch/build/light_switch.elf -m '/home/giang/.espressif/python_env/idf5.3_py3.12_env/bin/python' '/home/giang/project/esp-idf-v5.3.2/tools/idf.py' '-p' '/dev/ttyACM1'"... --- esp-idf-monitor 1.5.0 on /dev/ttyACM1 115200 --- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:2 load:0x40875720,len:0x18ec load:0x4086c110,len:0xe5c load:0x4086e610,len:0x2f4c entry 0x4086c11a I (23) boot: ESP-IDF v5.3.2 2nd stage bootloader I (24) boot: compile time Dec 19 2024 23:30:38 I (24) boot: chip revision: v0.0 I (26) boot: efuse block revision: v0.2 I (31) boot.esp32c6: SPI Speed : 80MHz I (36) boot.esp32c6: SPI Mode : DIO I (40) boot.esp32c6: SPI Flash Size : 4MB I (45) boot: Enabling RNG early entropy source... I (51) boot: Partition Table: I (54) boot: ## Label Usage Type ST Offset Length I (61) boot: 0 esp_secure_cert unknown 3f 06 0000d000 00002000 I (69) boot: 1 nvs WiFi data 01 02 00010000 0000c000 I (76) boot: 2 nvs_keys NVS keys 01 04 0001c000 00001000 I (84) boot: 3 otadata OTA data 01 00 0001d000 00002000 I (91) boot: 4 phy_init RF data 01 01 0001f000 00001000 I (99) boot: 5 ota_0 OTA app 00 10 00020000 001e0000 I (106) boot: 6 ota_1 OTA app 00 11 00200000 001e0000 I (114) boot: 7 fctry WiFi data 01 02 003e0000 00006000 I (121) boot: End of partition table I (126) esp_image: segment 0: paddr=00020020 vaddr=42140020 size=37444h (226372) map I (177) esp_image: segment 1: paddr=0005746c vaddr=40800000 size=08bach ( 35756) load I (185) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=13a940h (1288512) map I (427) esp_image: segment 3: paddr=0019a968 vaddr=40808bac size=0b010h ( 45072) load I (438) esp_image: segment 4: paddr=001a5980 vaddr=40813bc0 size=02d64h ( 11620) load I (441) esp_image: segment 5: paddr=001a86ec vaddr=50000000 size=00004h ( 4) load I (448) boot: Loaded app from partition at offset 0x20000 I (449) boot: Disabling RNG early entropy source... I (467) cpu_start: Unicore app I (475) cpu_start: Pro cpu start user code I (476) cpu_start: cpu freq: 160000000 Hz I (476) app_init: Application information: I (478) app_init: Project name: light_switch I (484) app_init: App version: 1.0 I (488) app_init: Compile time: Dec 19 2024 23:37:49 I (494) app_init: ELF file SHA256: ec9a389ec... I (500) app_init: ESP-IDF: v5.3.2 I (504) efuse_init: Min chip rev: v0.0 I (509) efuse_init: Max chip rev: v0.99 I (514) efuse_init: Chip rev: v0.0 I (519) heap_init: Initializing. RAM available for dynamic allocation: I (526) heap_init: At 4082D590 len 0004F080 (316 KiB): RAM I (532) heap_init: At 4087C610 len 00002F54 (11 KiB): RAM I (538) heap_init: At 50000004 len 00003FE4 (15 KiB): RTCRAM I (545) spi_flash: detected chip: generic I (549) spi_flash: flash io: dio W (553) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header. W (567) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h` I (578) sleep: Configure to isolate all GPIO pins in sleep state I (584) sleep: Enable automatic switching of GPIO sleep configuration I (591) coexist: coex firmware version: cbb41d7 I (596) coexist: coexist rom version 5b8dcfa I (602) main_task: Started on CPU0 I (602) main_task: Calling app_main() I (622) button: IoT Button Version: 3.4.1 I (622) gpio: GPIO[8]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (622) app_main: Switch created with endpoint_id 1 I (652) chip[DL]: NVS set: chip-counters/reboot-count = 6 (0x6) I (652) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC) I (652) BLE_INIT: Using main XTAL as clock source I (662) OPENTHREAD: Host connection mode none I (662) phy_init: phy_version 320,348a293,Sep 3 2024,16:33:12 I (662) BLE_INIT: ble controller commit:[4c64097] I (682) BLE_INIT: Bluetooth MAC: 40:4c:ca:58:01:32 I (722) phy: libbtbb version: 04952fd, Sep 3 2024, 16:33:30 I (732) NimBLE: GAP procedure initiated: stop advertising. I (732) NimBLE: Failed to restore IRKs from store; status=8 I (732) CHIP[DL]: BLE host-controller synced I (742) OPENTHREAD: OpenThread attached to netif I (742) chip[DL]: OpenThread started: OK I (752) chip[DL]: Setting OpenThread device type to ROUTER I (1252) chip[SVR]: Subscription persistence not supported I (1252) chip[SVR]: Server initializing... I (1252) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48 I (1252) chip[DMG]: AccessControl: initializing I (1262) chip[DMG]: Examples::AccessControlDelegate::Init I (1262) chip[DMG]: AccessControl: setting I (1272) chip[DMG]: DefaultAclStorage: initializing I (1272) chip[DMG]: DefaultAclStorage: 0 entries loaded I (1282) chip[SVR]: WARNING: mTestEventTriggerDelegate is null I (1302) chip[ZCL]: Using ZAP configuration... I (1302) esp_matter_cluster: Cluster plugin init common callback I (1302) chip[DMG]: AccessControlCluster: initializing I (1312) chip[ZCL]: 0x4214be38 ep 0 clus 0x0000_0030 attr 0x0000_0000 not supported I (1322) chip[ZCL]: Initiating Admin Commissioning cluster. I (1332) chip[DIS]: Updating services using commissioning mode 1 E (1332) chip[DIS]: Failed to remove advertised services: 3 I (1342) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0 E (1352) chip[DIS]: Failed to advertise commissionable node: 3 E (1352) chip[DIS]: Failed to finalize service update: 3 I (1362) chip[IN]: CASE Server enabling CASE session setups I (1372) chip[SVR]: Joining Multicast groups I (1372) chip[SVR]: Server Listening... I (1382) esp_matter_core: Dynamic endpoint 0 added I (1382) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000003's Attribute 0x00000001 is 0 ********** I (1392) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x00000000 is 128 ********** I (1402) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x0000FFFC is 1 ********** I (1422) esp_matter_core: Dynamic endpoint 1 added I (1432) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable) I (1432) NimBLE: GAP procedure initiated: advertise; I (1452) NimBLE: disc_mode=2 I (1452) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (1462) NimBLE: I (1462) chip[DL]: CHIPoBLE advertising started I (1472) app_main: Commissioning window opened > I (1962) main_task: Returned from app_main() [0nESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:2 load:0x40875720,len:0x18ec load:0x4086c110,len:0xe5c load:0x4086e610,len:0x2f4c entry 0x4086c11a I (23) boot: ESP-IDF v5.3.2 2nd stage bootloader I (24) boot: compile time Dec 19 2024 23:30:38 I (24) boot: chip revision: v0.0 I (26) boot: efuse block revision: v0.2 I (31) boot.esp32c6: SPI Speed : 80MHz I (36) boot.esp32c6: SPI Mode : DIO I (40) boot.esp32c6: SPI Flash Size : 4MB I (45) boot: Enabling RNG early entropy source... I (51) boot: Partition Table: I (54) boot: ## Label Usage Type ST Offset Length I (61) boot: 0 esp_secure_cert unknown 3f 06 0000d000 00002000 I (69) boot: 1 nvs WiFi data 01 02 00010000 0000c000 I (76) boot: 2 nvs_keys NVS keys 01 04 0001c000 00001000 I (84) boot: 3 otadata OTA data 01 00 0001d000 00002000 I (91) boot: 4 phy_init RF data 01 01 0001f000 00001000 I (99) boot: 5 ota_0 OTA app 00 10 00020000 001e0000 I (106) boot: 6 ota_1 OTA app 00 11 00200000 001e0000 I (114) boot: 7 fctry WiFi data 01 02 003e0000 00006000 I (121) boot: End of partition table I (126) esp_image: segment 0: paddr=00020020 vaddr=42140020 size=37444h (226372) map I (177) esp_image: segment 1: paddr=0005746c vaddr=40800000 size=08bach ( 35756) load I (185) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=13a940h (1288512) map I (427) esp_image: segment 3: paddr=0019a968 vaddr=40808bac size=0b010h ( 45072) load I (438) esp_image: segment 4: paddr=001a5980 vaddr=40813bc0 size=02d64h ( 11620) load I (441) esp_image: segment 5: paddr=001a86ec vaddr=50000000 size=00004h ( 4) load I (448) boot: Loaded app from partition at offset 0x20000 I (449) boot: Disabling RNG early entropy source... I (467) cpu_start: Unicore app I (475) cpu_start: Pro cpu start user code I (476) cpu_start: cpu freq: 160000000 Hz I (476) app_init: Application information: I (478) app_init: Project name: light_switch I (484) app_init: App version: 1.0 I (488) app_init: Compile time: Dec 19 2024 23:37:49 I (494) app_init: ELF file SHA256: ec9a389ec... I (500) app_init: ESP-IDF: v5.3.2 I (504) efuse_init: Min chip rev: v0.0 I (509) efuse_init: Max chip rev: v0.99 I (514) efuse_init: Chip rev: v0.0 I (519) heap_init: Initializing. RAM available for dynamic allocation: I (526) heap_init: At 4082D590 len 0004F080 (316 KiB): RAM I (532) heap_init: At 4087C610 len 00002F54 (11 KiB): RAM I (538) heap_init: At 50000004 len 00003FE4 (15 KiB): RTCRAM I (545) spi_flash: detected chip: generic I (549) spi_flash: flash io: dio W (553) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header. W (567) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h` I (578) sleep: Configure to isolate all GPIO pins in sleep state I (584) sleep: Enable automatic switching of GPIO sleep configuration I (591) coexist: coex firmware version: cbb41d7 I (596) coexist: coexist rom version 5b8dcfa I (602) main_task: Started on CPU0 I (602) main_task: Calling app_main() I (622) button: IoT Button Version: 3.4.1 I (622) gpio: GPIO[8]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (622) app_main: Switch created with endpoint_id 1 I (652) chip[DL]: NVS set: chip-counters/reboot-count = 7 (0x7) I (652) chip[DL]: Real time clock set to 946684800 (0100/00/01 00:00:00 UTC) I (652) BLE_INIT: Using main XTAL as clock source I (662) OPENTHREAD: Host connection mode none I (662) phy_init: phy_version 320,348a293,Sep 3 2024,16:33:12 I (662) BLE_INIT: ble controller commit:[4c64097] I (682) BLE_INIT: Bluetooth MAC: 40:4c:ca:58:01:32 I (722) phy: libbtbb version: 04952fd, Sep 3 2024, 16:33:30 I (732) NimBLE: GAP procedure initiated: stop advertising. I (732) NimBLE: Failed to restore IRKs from store; status=8 I (732) CHIP[DL]: BLE host-controller synced I (742) OPENTHREAD: OpenThread attached to netif I (742) chip[DL]: OpenThread started: OK I (752) chip[DL]: Setting OpenThread device type to ROUTER I (1252) chip[SVR]: Subscription persistence not supported I (1252) chip[SVR]: Server initializing... I (1252) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48 I (1252) chip[DMG]: AccessControl: initializing I (1262) chip[DMG]: Examples::AccessControlDelegate::Init I (1262) chip[DMG]: AccessControl: setting I (1272) chip[DMG]: DefaultAclStorage: initializing I (1272) chip[DMG]: DefaultAclStorage: 0 entries loaded I (1282) chip[SVR]: WARNING: mTestEventTriggerDelegate is null I (1302) chip[ZCL]: Using ZAP configuration... I (1302) esp_matter_cluster: Cluster plugin init common callback I (1302) chip[DMG]: AccessControlCluster: initializing I (1312) chip[ZCL]: 0x4214be38 ep 0 clus 0x0000_0030 attr 0x0000_0000 not supported I (1322) chip[ZCL]: Initiating Admin Commissioning cluster. I (1332) chip[DIS]: Updating services using commissioning mode 1 E (1332) chip[DIS]: Failed to remove advertised services: 3 I (1342) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0 E (1352) chip[DIS]: Failed to advertise commissionable node: 3 E (1352) chip[DIS]: Failed to finalize service update: 3 I (1362) chip[IN]: CASE Server enabling CASE session setups I (1372) chip[SVR]: Joining Multicast groups I (1372) chip[SVR]: Server Listening... I (1382) esp_matter_core: Dynamic endpoint 0 added I (1382) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000003's Attribute 0x00000001 is 0 ********** I (1392) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x00000000 is 128 ********** I (1402) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x0000FFFC is 1 ********** I (1422) esp_matter_core: Dynamic endpoint 1 added I (1432) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable) I (1432) NimBLE: GAP procedure initiated: advertise; I (1452) NimBLE: disc_mode=2 I (1452) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40 I (1462) NimBLE: I (1462) chip[DL]: CHIPoBLE advertising started I (1472) app_main: Commissioning window opened I (1522) main_task: Returned from app_main() > I (31332) chip[DL]: bleAdv Timeout : Start slow advertisement I (31332) chip[DL]: Configuring CHIPoBLE advertising (interval 500 ms, connectable) I (31342) chip[DL]: Device already advertising, stop active advertisement and restart I (31342) NimBLE: GAP procedure initiated: stop advertising. I (31352) NimBLE: GAP procedure initiated: advertise; I (31352) NimBLE: disc_mode=2 I (31362) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=800 adv_itvl_max=800 I (31372) NimBLE: I (171772) chip[DL]: BLE GAP connection established (con 0) I (171772) chip[DL]: CHIPoBLE advertising stopped I (173622) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (173632) chip[BLE]: local and remote recv window sizes = 5 I (173642) chip[BLE]: selected BTP version 4 I (173642) chip[BLE]: using BTP fragment sizes rx 244 / tx 244. I (173722) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 0 ) indicate = 1 I (173732) chip[DL]: CHIPoBLE subscribe received I (173732) NimBLE: GATT procedure initiated: indicate; I (173742) NimBLE: att_handle=18 I (173822) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (173832) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (173842) chip[EM]: >>> [E:48690r S:0 M:119888098] (U) Msg RX from 0:E34CF4CAF43A1403 [0000] to 0000000000000000 --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98) I (173852) chip[EM]: <<< [E:48690r S:0 M:181910630] (U) Msg TX from 0000000000000000 to 0:E34CF4CAF43A1403 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154) I (173872) NimBLE: GATT procedure initiated: indicate; I (173882) NimBLE: att_handle=18 I (173882) chip[SVR]: Commissioning session establishment step started I (174072) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (174082) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (174092) chip[EM]: >>> [E:48690r S:0 M:119888099] (U) Msg RX from 0:E34CF4CAF43A1403 [0000] to 0000000000000000 --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92) I (174162) chip[EM]: <<< [E:48690r S:0 M:181910631] (U) Msg TX from 0000000000000000 to 0:E34CF4CAF43A1403 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127) I (174172) NimBLE: GATT procedure initiated: indicate; I (174172) NimBLE: att_handle=18 I (174322) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (174372) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (174382) chip[EM]: >>> [E:48690r S:0 M:119888100] (U) Msg RX from 0:E34CF4CAF43A1403 [0000] to 0000000000000000 --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59) I (174392) chip[EM]: <<< [E:48690r S:0 M:181910632] (U) Msg TX from 0000000000000000 to 0:E34CF4CAF43A1403 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) (B:30) I (174412) NimBLE: GATT procedure initiated: indicate; I (174412) NimBLE: att_handle=18 I (174422) chip[SC]: SecureSession[0x40819d58, LSID:3027]: State change 'kEstablishing' --> 'kActive' I (174432) chip[SVR]: Commissioning completed session establishment step I (174442) chip[DIS]: Updating services using commissioning mode 0 E (174442) chip[DIS]: Failed to remove advertised services: 3 I (174452) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=0 cp=0 E (174462) chip[DIS]: Failed to advertise extended commissionable node: 3 E (174472) chip[DIS]: Failed to finalize service update: 3 I (174472) chip[SVR]: Device completed Rendezvous process I (174482) app_main: Commissioning session started I (174482) app_main: Commissioning window closed I (174472) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (174502) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (174512) chip[EM]: >>> [E:48691r S:3027 M:183466376] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:131) I (174532) chip[DL]: NVS set: chip-config/reg-location = 0 (0x0) I (174532) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 ********** I (174542) chip[EM]: <<< [E:48691r S:3027 M:205778378] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:258) I (174552) NimBLE: GATT procedure initiated: indicate; I (174562) NimBLE: att_handle=18 I (174672) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (174682) NimBLE: GATT procedure initiated: indicate; I (174692) NimBLE: att_handle=18 I (174822) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (174882) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (174882) chip[EM]: >>> [E:48692r S:3027 M:183466377] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:106) E (174892) chip[DMG]: Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0002err = 5c3 E (174912) chip[DMG]: Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0001err = 5c3 E (174922) chip[DMG]: Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0000err = 5c3 E (174932) chip[DMG]: Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0007err = 5c3 E (174942) chip[DMG]: Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0006err = 5c3 I (174962) chip[EM]: <<< [E:48692r S:3027 M:205778379] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:180) I (174982) NimBLE: GATT procedure initiated: indicate; I (174982) NimBLE: att_handle=18 I (175122) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (175132) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (175142) chip[EM]: >>> [E:48693r S:3027 M:183466378] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65) I (175152) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x00000030 I (175162) chip[FS]: GeneralCommissioning: Received ArmFailSafe (60s) I (175162) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 ********** I (175182) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 4 ********** I (175192) chip[EM]: <<< [E:48693r S:3027 M:205778380] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) I (175212) NimBLE: GATT procedure initiated: indicate; I (175212) NimBLE: att_handle=18 I (175322) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (175332) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (175342) chip[EM]: >>> [E:48694r S:3027 M:183466379] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:70) I (175352) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x00000030 I (175362) chip[DL]: NVS set: chip-config/reg-location = 0 (0x0) I (175382) chip[DL]: NVS set: chip-config/country-code = "XX" I (175382) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 4 ********** I (175392) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 5 ********** I (175402) chip[EM]: <<< [E:48694r S:3027 M:205778381] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) I (175412) NimBLE: GATT procedure initiated: indicate; I (175422) NimBLE: att_handle=18 I (175572) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (175622) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (175632) chip[EM]: >>> [E:48695r S:3027 M:183466380] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62) I (175642) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x0000003E I (175652) chip[ZCL]: OpCreds: Certificate Chain request received for PAI I (175672) chip[EM]: <<< [E:48695r S:3027 M:205778382] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:527) I (175682) NimBLE: GATT procedure initiated: indicate; I (175682) NimBLE: att_handle=18 I (175872) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (175882) NimBLE: GATT procedure initiated: indicate; I (175892) NimBLE: att_handle=18 I (176022) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (176032) NimBLE: GATT procedure initiated: indicate; I (176042) NimBLE: att_handle=18 I (176172) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (176232) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (176232) chip[EM]: >>> [E:48696r S:3027 M:183466381] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62) I (176242) esp_matter_command: Received command 0x00000002 for endpoint 0x0000's cluster 0x0000003E I (176252) chip[ZCL]: OpCreds: Certificate Chain request received for DAC I (176272) chip[EM]: <<< [E:48696r S:3027 M:205778383] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:557) I (176282) NimBLE: GATT procedure initiated: indicate; I (176282) NimBLE: att_handle=18 I (176572) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (176582) NimBLE: GATT procedure initiated: indicate; I (176592) NimBLE: att_handle=18 I (176722) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (176732) NimBLE: GATT procedure initiated: indicate; I (176742) NimBLE: att_handle=18 I (176822) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (176832) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (176842) chip[EM]: >>> [E:48697r S:3027 M:183466382] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94) I (176852) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x0000003E I (176862) chip[ZCL]: OpCreds: Received an AttestationRequest command I (176882) chip[ZCL]: OpCreds: AttestationRequest successful. I (176892) chip[EM]: <<< [E:48697r S:3027 M:205778384] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:714) I (176902) NimBLE: GATT procedure initiated: indicate; I (176902) NimBLE: att_handle=18 I (177022) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (177032) NimBLE: GATT procedure initiated: indicate; I (177042) NimBLE: att_handle=18 I (177172) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (177182) NimBLE: GATT procedure initiated: indicate; I (177192) NimBLE: att_handle=18 I (177322) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (177332) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (177342) chip[EM]: >>> [E:48698r S:3027 M:183466383] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94) I (177352) esp_matter_command: Received command 0x00000004 for endpoint 0x0000's cluster 0x0000003E I (177362) chip[ZCL]: OpCreds: Received a CSRRequest command I (177392) chip[ZCL]: OpCreds: AllocatePendingOperationalKey succeeded I (177412) chip[ZCL]: OpCreds: CSRRequest successful. I (177412) chip[EM]: <<< [E:48698r S:3027 M:205778385] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:372) I (177432) NimBLE: GATT procedure initiated: indicate; I (177432) NimBLE: att_handle=18 I (177622) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (177632) NimBLE: GATT procedure initiated: indicate; I (177642) NimBLE: att_handle=18 I (177722) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (177832) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (177932) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (177932) chip[EM]: >>> [E:48699r S:3027 M:183466384] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:293) I (177942) esp_matter_command: Received command 0x0000000B for endpoint 0x0000's cluster 0x0000003E I (177952) chip[ZCL]: OpCreds: Received an AddTrustedRootCertificate command I (177992) chip[ZCL]: OpCreds: AddTrustedRootCertificate successful. I (178002) chip[EM]: <<< [E:48699r S:3027 M:205778386] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:63) I (178012) NimBLE: GATT procedure initiated: indicate; I (178022) NimBLE: att_handle=18 I (178122) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (178182) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (178382) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (178532) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (178532) chip[EM]: >>> [E:48700r S:3027 M:183466385] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:566) I (178542) esp_matter_command: Received command 0x00000006 for endpoint 0x0000's cluster 0x0000003E I (178552) chip[ZCL]: OpCreds: Received an AddNOC command I (178562) chip[FP]: Validating NOC chain I (178632) chip[FP]: NOC chain validation successful I (178632) chip[FP]: Added new fabric at index: 0x1 I (178632) chip[FP]: Assigned compressed fabric ID: 0x26C29F5EF81D8824, node ID: 0x0000000000000002 I (178642) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48 I (178652) chip[TS]: New proposed Last Known Good Time: 2021-01-01T00:00:00 I (178652) chip[TS]: Retaining current Last Known Good Time I (178672) chip[ZCL]: OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669 I (178672) chip[DIS]: Advertise operational node 26C29F5EF81D8824-0000000000000002 E (178682) chip[SVR]: Operational advertising failed: 3 I (178692) chip[ZCL]: OpCreds: successfully created fabric index 0x1 via AddNOC I (178702) chip[EM]: <<< [E:48700r S:3027 M:205778387] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [8824] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) I (178712) NimBLE: GATT procedure initiated: indicate; I (178722) NimBLE: att_handle=18 I (178772) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (178822) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (178832) chip[EM]: >>> [E:48701r S:3027 M:183466386] (S) Msg RX from 1:FFFFFFFB00000000 [8824] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:171) I (178842) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 5 ********** I (178852) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 24 ********** I (178872) chip[EM]: <<< [E:48701r S:3027 M:205778388] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [8824] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) I (178882) NimBLE: GATT procedure initiated: indicate; I (178892) NimBLE: att_handle=18 I (178972) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (178982) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (178992) chip[EM]: >>> [E:48702r S:3027 M:183466387] (S) Msg RX from 1:FFFFFFFB00000000 [8824] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65) I (179002) esp_matter_command: Received command 0x00000000 for endpoint 0x0000's cluster 0x00000030 I (179012) chip[FS]: GeneralCommissioning: Received ArmFailSafe (136s) I (179012) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 24 ********** I (179032) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 26 ********** I (179042) chip[EM]: <<< [E:48702r S:3027 M:205778389] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [8824] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) I (179062) NimBLE: GATT procedure initiated: indicate; I (179062) NimBLE: att_handle=18 I (179222) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (179282) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (179282) chip[EM]: >>> [E:48703r S:3027 M:183466388] (S) Msg RX from 1:FFFFFFFB00000000 [8824] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:73) I(179302) OPENTHREAD:[N] Mle-----------: Role disabled -> detached I (179302) chip[DL]: Updating advertising data I (179302) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3 I (179312) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3 I (179322) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3 I (179332) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3 I (179312) OT_STATE: netif up I(179982) OPENTHREAD:[N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset I(180872) OPENTHREAD:[N] Mle-----------: RLOC16 fffe -> f801 I(180872) OPENTHREAD:[N] Mle-----------: Role detached -> child I (180902) chip[DL]: SRP Client was started, detected server: fdde:ad00:beef:0000:9cfd:a14d:3c76:e6d2 I (180902) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3 I (180902) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3 I (180912) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 26 ********** I (180932) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 28 ********** I (180942) chip[EM]: <<< [E:48703r S:3027 M:205778390] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [8824] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:65) I (180952) NimBLE: GATT procedure initiated: indicate; I (180962) NimBLE: att_handle=18 I (180962) chip[DIS]: Advertise operational node 26C29F5EF81D8824-0000000000000002 E (180972) chip[SVR]: Operational advertising failed: 3 I (181072) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (181562) chip[SVR]: Server initialization complete I (181572) chip[DIS]: Updating services using commissioning mode 0 I (181582) chip[DIS]: Advertise operational node 26C29F5EF81D8824-0000000000000002 I (181582) chip[DL]: advertising srp service: 26C29F5EF81D8824-0000000000000002._matter._tcp I (181592) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=0 cp=0 I (181612) chip[DL]: advertising srp service: B9DBEE94BD42816D._matterc._udp I (181612) chip[SWU]: Stopping the watchdog timer I (181612) chip[SWU]: Starting the periodic query timer, timeout: 86400 seconds I (181622) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x0000002A's Attribute 0x00000002 is 0 ********** I (181632) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x0000002A's Attribute 0x00000002 is 0 ********** I (181642) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x0000002A's Attribute 0x00000002 is 1 ********** I (181662) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x0000002A's Attribute 0x00000003 is null ********** I (181672) chip[SVR]: Cannot load binding table: a0 W(182192) OPENTHREAD:[W] DuaManager----: Failed to perform next registration: NotFound I (183572) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (186082) NimBLE: GATT procedure initiated: indicate; I (186082) NimBLE: att_handle=18 I (186172) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (188672) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (191182) NimBLE: GATT procedure initiated: indicate; I (191182) NimBLE: att_handle=18 I (191272) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (193772) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16 I (196282) NimBLE: GATT procedure initiated: indicate; I (196282) NimBLE: att_handle=18 I (196372) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 I (196382) chip[EM]: >>> [E:48704r S:0 M:119888101] (U) Msg RX from 0:3EE69BF61E685C7C [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196) I (196402) chip[IN]: CASE Server received Sigma1 message . Starting handshake. EC 0x4081b788 I (196412) chip[EM]: <<< [E:48704r S:0 M:181910633 (Ack:119888101)] (U) Msg TX from 0000000000000000 to 0:3EE69BF61E685C7C [0000] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:37346] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) I (196422) chip[SC]: Received Sigma1 msg I (196432) chip[SC]: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000002 I (196482) chip[EM]: <<< [E:48704r S:0 M:181910634 (Ack:119888101)] (U) Msg TX from 0000000000000000 to 0:3EE69BF61E685C7C [0000] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:37346] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751) I (196492) chip[EM]: ??1 [E:48704r S:0 M:181910634] (U) Msg Retransmission to 0:0000000000000000 in 5352ms [State:Active II:500 AI:300 AT:4000] I (196502) chip[SC]: Sent Sigma2 msg I (196842) chip[EM]: >>> [E:48704r S:0 M:119888102 (Ack:181910634)] (U) Msg RX from 0:3EE69BF61E685C7C [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598) I (196862) chip[EM]: <<< [E:48704r S:0 M:181910635 (Ack:119888102)] (U) Msg TX from 0000000000000000 to 0:3EE69BF61E685C7C [0000] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:37346] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) I (196882) chip[SC]: Received Sigma3 msg E (196882) chip[SC]: The device does not support GetClock_RealTimeMS() API: 6c. Falling back to Last Known Good UTC Time I (196992) chip[EM]: <<< [E:48704r S:0 M:181910636 (Ack:119888102)] (U) Msg TX from 0000000000000000 to 0:3EE69BF61E685C7C [0000] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:37346] --- Type 0000:40 (SecureChannel:StatusReport) (B:34) I (197012) chip[EM]: ??1 [E:48704r S:0 M:181910636] (U) Msg Retransmission to 0:0000000000000000 in 5373ms [State:Active II:500 AI:300 AT:4000] I (197022) chip[SC]: SecureSession[0x40819e30, LSID:3028]: State change 'kEstablishing' --> 'kActive' I (197032) chip[IN]: CASE Session established to peer: <000000000001B669, 1> I (197352) chip[EM]: >>> [E:48705r S:3028 M:83117743] (S) Msg RX from 1:000000000001B669 [8824] to 0000000000000002 --- Type 0001:08 (IM:InvokeCommandRequest) (B:59) I (197362) esp_matter_command: Received command 0x00000004 for endpoint 0x0000's cluster 0x00000030 I (197362) chip[FS]: GeneralCommissioning: Received CommissioningComplete I (197382) chip[FP]: Metadata for Fabric 0x1 persisted to storage. I (197392) chip[TS]: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 I (197392) chip[ZCL]: OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x26C29F5EF81D8824, FabricId 0000000000000001, NodeId 0000000000000002, VendorId 0xFFF1 I (197422) chip[FS]: GeneralCommissioning: Successfully commited pending fabric data I (197422) chip[FS]: Fail-safe cleanly disarmed I (197432) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 28 ********** I (197442) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 ********** I (197452) chip[EM]: <<< [E:48705r S:3028 M:185114833 (Ack:83117743)] (S) Msg TX from 0000000000000002 to 1:000000000001B669 [8824] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:37346] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70) I (197472) chip[EM]: ??1 [E:48705r S:3028 M:185114833] (S) Msg Retransmission to 1:000000000001B669 in 5336ms [State:Active II:500 AI:300 AT:4000] I (197482) chip[EM]: >>> [E:48704r S:0 M:119888103 (Ack:181910636)] (U) Msg RX from 0:3EE69BF61E685C7C [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) I (197502) chip[SWU]: Device commissioned, schedule a default provider query I (197502) chip[SVR]: Commissioning completed successfully I (197522) chip[DIS]: Updating services using commissioning mode 0 I (197532) chip[DIS]: Advertise operational node 26C29F5EF81D8824-0000000000000002 I (197532) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=0 cp=0 I (197522) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 0 ) indicate = 0 I (197562) chip[DL]: CHIPoBLE unsubscribe received I (197552) chip[SC]: SecureSession[0x40819d58, LSID:3027]: State change 'kActive' --> 'kPendingEviction' I (197572) chip[BLE]: Releasing end point's BLE connection back to application. I (197582) chip[DL]: Closing BLE GATT connection (con 0) I (197582) NimBLE: GAP procedure initiated: terminate connection; conn_handle=0 hci_reason=19 I (197602) app_main: Commissioning complete I (197602) esp_matter_core: Commissioning Complete I (197602) app_main: Commissioning window closed I (197822) chip[DL]: BLE GAP connection terminated (con 0 reason 0x216) I (197832) esp_matter_core: BLE Disconnected I (197882) chip[EM]: >>> [E:48705r S:3028 M:83117744 (Ack:185114833)] (S) Msg RX from 1:000000000001B669 [8824] to 0000000000000002 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34) E (227512) chip[SWU]: No suitable OTA Provider candidate found I (227512) chip[SWU]: No provider available I(228212) OPENTHREAD:[N] Mle-----------: RLOC16 f801 -> 5400 I(228212) OPENTHREAD:[N] Mle-----------: Role child -> router I(228222) OPENTHREAD:[N] Mle-----------: Partition ID 0x7f15793 I (336312) chip[EM]: >>> [E:9730r S:0 M:260620119] (U) Msg RX from 0:FBC25FBF62AAD404 [0000] to 0000000000000000 --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196) I (336322) chip[IN]: CASE Server received Sigma1 message . Starting handshake. EC 0x4081b788 I (336332) chip[EM]: <<< [E:9730r S:0 M:181910637 (Ack:260620119)] (U) Msg TX from 0000000000000000 to 0:FBC25FBF62AAD404 [0000] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:43906] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) I (336352) chip[SC]: Received Sigma1 msg I (336362) chip[SC]: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000002 I (336402) chip[EM]: <<< [E:9730r S:0 M:181910638 (Ack:260620119)] (U) Msg TX from 0000000000000000 to 0:FBC25FBF62AAD404 [0000] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:43906] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751) I (336422) chip[EM]: ??1 [E:9730r S:0 M:181910638] (U) Msg Retransmission to 0:0000000000000000 in 5339ms [State:Active II:500 AI:300 AT:4000] I (336432) chip[SC]: Sent Sigma2 msg I (336832) chip[EM]: >>> [E:9730r S:0 M:260620120 (Ack:181910638)] (U) Msg RX from 0:FBC25FBF62AAD404 [0000] to 0000000000000000 --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598) I (336842) chip[EM]: <<< [E:9730r S:0 M:181910639 (Ack:260620120)] (U) Msg TX from 0000000000000000 to 0:FBC25FBF62AAD404 [0000] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:43906] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) I (336872) chip[SC]: Received Sigma3 msg E (336872) chip[SC]: The device does not support GetClock_RealTimeMS() API: 6c. Falling back to Last Known Good UTC Time I (336982) chip[EM]: <<< [E:9730r S:0 M:181910640 (Ack:260620120)] (U) Msg TX from 0000000000000000 to 0:FBC25FBF62AAD404 [0000] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:43906] --- Type 0000:40 (SecureChannel:StatusReport) (B:34) I (337002) chip[EM]: ??1 [E:9730r S:0 M:181910640] (U) Msg Retransmission to 0:0000000000000000 in 5384ms [State:Active II:500 AI:300 AT:4000] I (337012) chip[SC]: SecureSession[0x40819f08, LSID:3029]: State change 'kEstablishing' --> 'kActive' I (337022) chip[IN]: CASE Session established to peer: <000000000001B669, 1> I (337062) chip[EM]: >>> [E:9731r S:3029 M:95086708] (S) Msg RX from 1:000000000001B669 [8824] to 0000000000000002 --- Type 0001:08 (IM:InvokeCommandRequest) (B:59) E (337082) chip[DMG]: Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0001 status 0xc3 (no additional context) I (337092) chip[EM]: <<< [E:9731r S:3029 M:255784890 (Ack:95086708)] (S) Msg TX from 0000000000000002 to 1:000000000001B669 [8824] [UDP:[FDDE:AD00:BEEF:CAFE:6C77:E7D4:906E:1678]:43906] --- Type 0001:09 (IM:InvokeCommandResponse) (B:67) I (337112) chip[EM]: ??1 [E:9731r S:3029 M:255784890] (S) Msg Retransmission to 1:000000000001B669 in 5398ms [State:Active II:500 AI:300 AT:4000] I (337122) chip[EM]: >>> [E:9730r S:0 M:260620121 (Ack:181910640)] (U) Msg RX from 0:FBC25FBF62AAD404 [0000] to 0000000000000000 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) I (337172) chip[EM]: >>> [E:9731r S:3029 M:95086709 (Ack:255784890)] (S) Msg RX from 1:000000000001B669 [8824] to 0000000000000002 --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34)