I am currently working with the Nordic nRF5340DK board using the official Matter light bulb example from the nRF Connect SDK version 3.1.0. I am also using the nordicconnectedhomeip repository version 3.1.0 along with the chip-tool command line tool version 3.1.0 on Rpi5+nrf52840 dongle for commissioning.
Despite following the standard commissioning process, I am unable to commission the device successfully. The chip-tool and firmware produce commissioning failures, including device attestation errors and continuous failures to advertise the commissionable node over Thread (error code 3).
I am attaching the chip-tool output log and device firmware log window for reference. The logs show:
-
Attestation verification failing due to "mbedTLS error: ECP - The signature is not valid" and "Failed Device Attestation".
-
Firmware complaints about "Failed to advertise commissionable node: 3" and fail-safe timer expirations.
-
Secure session and pairing over BLE appear to function fine, but commissioning still fails.
I have used unmodified Nordic example firmware and tools, so I suspect the issue may be related to environment setup, certificate handling, or potential edge bugs in NCS 3.1.0 or the chip-tool.
Any insights, suggestions, or similar experiences would be very helpful. Thank you in advance!
log from CHIP tool
linux1@linux1-Vishal:~/Downloads$ ./chip-tool_x64 pairing ble-thread 1 hex:0e08000000000001000000030000194a0300001035060004001fffe00208347d53a051e5dd230708fda2fa62ad804c48051011d9d5160e2daa7166ef77a9b4187a6a030f4f70656e5468726561642d3330313901023019041040972111cdc035de2d1ef7203a3580380c0402a0f7f8 20202021 3840
[1757438792.284] [45354:45354] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1757438792.284] [45354:45354] [DL] ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs, IGNORING.
[1757438792.284] [45354:45354] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1757438792.284] [45354:45354] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1757438792.284] [45354:45354] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1757438792.298] [45354:45354] [DL] Wrote settings to /tmp/chip_counters.ini
[1757438792.298] [45354:45354] [DL] NVS set: chip-counters/reboot-count = 18 (0x12)
[1757438792.299] [45354:45354] [DL] Failed to get Ethernet interface
[1757438792.299] [45354:45354] [DL] Failed to reset Ethernet statistic counts
[1757438792.299] [45354:45354] [DL] Got WiFi interface: wlp0s20f3
[1757438792.299] [45354:45354] [DL] Found the primary WiFi interface:wlp0s20f3
[1757438792.299] [45354:45354] [PAF] WiFiPAF: WiFiPAFLayer::Init()
[1757438792.299] [45354:45354] [IN] UDP::Init bind&listen port=0
[1757438792.299] [45354:45354] [IN] UDP::Init bound to port=57486
[1757438792.299] [45354:45354] [IN] UDP::Init bind&listen port=0
[1757438792.299] [45354:45354] [IN] UDP::Init bound to port=50977
[1757438792.299] [45354:45354] [IN] BLEBase::Init - setting/overriding transport
[1757438792.299] [45354:45354] [IN] WiFiPAFBase::Init - setting/overriding transport
[1757438792.299] [45354:45354] [IN] TransportMgr initialized
[1757438792.299] [45354:45354] [FP] Initializing FabricTable from persistent storage
[1757438792.299] [45354:45354] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1757438792.300] [45354:45354] [FP] Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xD424E20FF510BCCC, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1757438792.300] [45354:45354] [DMG] Ember attribute persistence requires setting up
[1757438792.300] [45354:45354] [ZCL] Using ZAP configuration...
[1757438792.301] [45354:45354] [DL] Avahi client registered
[1757438792.301] [45354:45354] [CTL] System State Initialized...
[1757438792.301] [45354:45354] [CTL] Setting attestation nonce to random value
[1757438792.301] [45354:45354] [CTL] Setting CSR nonce to random value
[1757438792.301] [45354:45356] [DL] CHIP task running
[1757438792.301] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 32786
[1757438792.301] [45354:45356] [CTL] Setting attestation nonce to random value
[1757438792.302] [45354:45356] [CTL] Setting CSR nonce to random value
[1757438792.304] [45354:45356] [CTL] Generating NOC
[1757438792.306] [45354:45356] [FP] Validating NOC chain
[1757438792.311] [45354:45356] [FP] NOC chain validation successful
[1757438792.311] [45354:45356] [FP] Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1757438792.311] [45354:45356] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1757438792.311] [45354:45356] [TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
[1757438792.311] [45354:45356] [TS] Retaining current Last Known Good Time
[1757438792.311] [45354:45356] [FP] Metadata for Fabric 0x1 persisted to storage.
[1757438792.311] [45354:45356] [TS] Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1757438792.311] [45354:45356] [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: D424E20FF510BCCC)
[1757438792.312] [45354:45356] [CTL] Setting thread operational dataset from parameters
[1757438792.312] [45354:45356] [CTL] Setting attestation nonce to random value
[1757438792.312] [45354:45356] [CTL] Setting CSR nonce to random value
[1757438792.312] [45354:45356] [CTL] Commission called for node ID 0x0000000000000001
[1757438792.314] [45354:45355] [BLE] BLE removing known devices
[1757438792.314] [45354:45355] [BLE] BLE initiating scan
[1757438792.431] [45354:45356] [BLE] ChipDeviceScanner has started scanning!
[1757438792.431] [45354:45356] [DL] Long dispatch time: 119 ms, for event type 3
[1757438792.435] [45354:45355] [BLE] Device 7F:10:0D:F2:E1:B5 does not look like a CHIP device.
[1757438792.444] [45354:45355] [BLE] Device CC:03:7B:5E:94:46 does not look like a CHIP device.
[1757438792.444] [45354:45355] [BLE] Device 2D:0C:D8:57:F8:72 does not look like a CHIP device.
[1757438792.449] [45354:45355] [BLE] Device 65:F5:54:86:AB:F0 does not look like a CHIP device.
[1757438792.450] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.497] [45354:45355] [BLE] Device 4C:C5:CF:9B:3B:95 does not look like a CHIP device.
[1757438792.498] [45354:45355] [BLE] Device 32:13:8B:01:0C:CB does not look like a CHIP device.
[1757438792.498] [45354:45355] [BLE] Device 1D:79:68:3D:EC:3D does not look like a CHIP device.
[1757438792.501] [45354:45355] [BLE] Device 5C:83:AC:52:E0:F6 does not look like a CHIP device.
[1757438792.509] [45354:45355] [BLE] Device C7:80:9D:80:D4:B9 does not look like a CHIP device.
[1757438792.509] [45354:45355] [BLE] Device 16:CB:19:32:53:11 does not look like a CHIP device.
[1757438792.511] [45354:45355] [BLE] Device 7F:59:BD:C0:B4:46 does not look like a CHIP device.
[1757438792.512] [45354:45355] [BLE] Device 33:CE:4E:97:C2:75 does not look like a CHIP device.
[1757438792.513] [45354:45355] [BLE] Device CB:C4:49:CD:DC:6B does not look like a CHIP device.
[1757438792.524] [45354:45355] [BLE] Device 1F:6C:DA:3F:49:5E does not look like a CHIP device.
[1757438792.543] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.558] [45354:45355] [BLE] Device 30:62:26:00:06:9D does not look like a CHIP device.
[1757438792.561] [45354:45355] [BLE] Device 00:81:F9:1D:6B:77 does not look like a CHIP device.
[1757438792.561] [45354:45355] [BLE] Device 3C:21:D0:CF:47:F8 does not look like a CHIP device.
[1757438792.565] [45354:45355] [BLE] Device 26:41:38:2A:F6:B9 does not look like a CHIP device.
[1757438792.571] [45354:45355] [BLE] Device 75:23:71:12:84:2A does not look like a CHIP device.
[1757438792.572] [45354:45355] [BLE] Device 75:45:23:16:4E:59 does not look like a CHIP device.
[1757438792.580] [45354:45355] [BLE] Device 04:4B:ED:B2:F3:27 does not look like a CHIP device.
[1757438792.584] [45354:45355] [BLE] Device 43:44:9B:CC:9E:E5 does not look like a CHIP device.
[1757438792.585] [45354:45355] [BLE] Device 1D:0A:3F:40:D5:A1 does not look like a CHIP device.
[1757438792.587] [45354:45355] [BLE] Device 0C:67:EC:66:D1:43 does not look like a CHIP device.
[1757438792.588] [45354:45355] [BLE] Device 2D:02:46:F8:BA:3E does not look like a CHIP device.
[1757438792.592] [45354:45355] [BLE] Device 12:01:70:01:D2:C4 does not look like a CHIP device.
[1757438792.597] [45354:45355] [BLE] Device E4:FA:5B:9D:18:10 does not look like a CHIP device.
[1757438792.605] [45354:45355] [BLE] Device CC:03:7B:5E:94:46 does not look like a CHIP device.
[1757438792.606] [45354:45355] [BLE] Device 05:68:A6:E0:6A:0C does not look like a CHIP device.
[1757438792.612] [45354:45355] [BLE] Device 4A:F1:25:EF:45:FF does not look like a CHIP device.
[1757438792.613] [45354:45355] [BLE] Device 2B:42:50:00:43:2F does not look like a CHIP device.
[1757438792.614] [45354:45355] [BLE] Device 27:03:71:07:51:35 does not look like a CHIP device.
[1757438792.617] [45354:45355] [BLE] Device 16:CB:19:32:53:11 does not look like a CHIP device.
[1757438792.621] [45354:45355] [BLE] Device 33:CE:4E:97:C2:75 does not look like a CHIP device.
[1757438792.623] [45354:45355] [BLE] Device 1F:6C:DA:3F:49:5E does not look like a CHIP device.
[1757438792.632] [45354:45355] [BLE] Device 14:E4:D3:E0:08:69 does not look like a CHIP device.
[1757438792.639] [45354:45355] [BLE] Device 1A:46:EA:B3:80:95 does not look like a CHIP device.
[1757438792.641] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.646] [45354:45355] [BLE] Device CC:03:7B:5E:94:46 does not look like a CHIP device.
[1757438792.647] [45354:45355] [BLE] Device 18:E1:60:F4:4B:CC does not look like a CHIP device.
[1757438792.656] [45354:45355] [BLE] Device 2D:0C:D8:57:F8:72 does not look like a CHIP device.
[1757438792.662] [45354:45355] [BLE] Device 13:44:DA:8C:AB:EF does not look like a CHIP device.
[1757438792.672] [45354:45355] [BLE] Device C6:91:6F:11:60:F4 does not look like a CHIP device.
[1757438792.678] [45354:45355] [BLE] Device 5E:CF:09:54:64:3C does not look like a CHIP device.
[1757438792.678] [45354:45355] [BLE] Device 26:41:38:2A:F6:B9 does not look like a CHIP device.
[1757438792.690] [45354:45355] [BLE] Device 0C:67:EC:66:D1:43 does not look like a CHIP device.
[1757438792.693] [45354:45355] [BLE] Device 1D:0A:3F:40:D5:A1 does not look like a CHIP device.
[1757438792.694] [45354:45355] [BLE] Device 5E:EF:94:EF:82:82 does not look like a CHIP device.
[1757438792.702] [45354:45355] [BLE] Device 14:9C:EF:4A:DB:F7 does not look like a CHIP device.
[1757438792.703] [45354:45355] [BLE] Device 1C:1B:51:84:BA:5A does not look like a CHIP device.
[1757438792.704] [45354:45355] [BLE] Device 4D:3D:01:A0:6E:FD does not look like a CHIP device.
[1757438792.707] [45354:45355] [BLE] Device C7:80:9D:80:D4:B9 does not look like a CHIP device.
[1757438792.708] [45354:45355] [BLE] Device 4D:F2:32:9A:94:A6 does not look like a CHIP device.
[1757438792.714] [45354:45355] [BLE] Device 32:13:8B:01:0C:CB does not look like a CHIP device.
[1757438792.722] [45354:45355] [BLE] Device CA:B9:EB:65:C4:B6 does not look like a CHIP device.
[1757438792.722] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.724] [45354:45355] [BLE] Device C6:91:6F:11:60:F4 does not look like a CHIP device.
[1757438792.728] [45354:45355] [BLE] Device CC:03:7B:5E:94:46 does not look like a CHIP device.
[1757438792.729] [45354:45355] [BLE] Device 36:10:D2:00:91:B2 does not look like a CHIP device.
[1757438792.731] [45354:45355] [BLE] Device 33:CE:4E:97:C2:75 does not look like a CHIP device.
[1757438792.735] [45354:45355] [BLE] Device 2F:C6:66:13:DF:5A does not look like a CHIP device.
[1757438792.737] [45354:45355] [BLE] Device 75:45:23:16:4E:59 does not look like a CHIP device.
[1757438792.738] [45354:45355] [BLE] Device 14:E4:D3:E0:08:69 does not look like a CHIP device.
[1757438792.748] [45354:45355] [BLE] Device 0E:FA:29:DE:88:A3 does not look like a CHIP device.
[1757438792.752] [45354:45355] [BLE] Device CC:03:7B:5E:94:46 does not look like a CHIP device.
[1757438792.755] [45354:45355] [BLE] Device 18:E1:60:F4:4B:CC does not look like a CHIP device.
[1757438792.765] [45354:45355] [BLE] Device 75:23:71:12:84:2A does not look like a CHIP device.
[1757438792.766] [45354:45355] [BLE] Device 2D:0C:D8:57:F8:72 does not look like a CHIP device.
[1757438792.770] [45354:45355] [BLE] Device 5B:3F:94:B7:51:A4 does not look like a CHIP device.
[1757438792.771] [45354:45355] [BLE] Device 3C:21:D0:CF:47:F8 does not look like a CHIP device.
[1757438792.773] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.787] [45354:45355] [BLE] Device 7E:57:58:2A:F9:87 does not look like a CHIP device.
[1757438792.793] [45354:45355] [BLE] Device 2D:88:55:B7:A0:64 does not look like a CHIP device.
[1757438792.795] [45354:45355] [BLE] Device 1D:0A:3F:40:D5:A1 does not look like a CHIP device.
[1757438792.798] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.800] [45354:45355] [BLE] Device 11:91:A4:B1:48:F1 does not look like a CHIP device.
[1757438792.802] [45354:45355] [BLE] Device C9:40:BE:79:CB:4D does not look like a CHIP device.
[1757438792.806] [45354:45355] [BLE] Device 12:01:70:01:D2:C4 does not look like a CHIP device.
[1757438792.813] [45354:45355] [BLE] Device C6:91:6F:11:60:F4 does not look like a CHIP device.
[1757438792.820] [45354:45355] [BLE] Device 50:EA:97:3F:FF:06 does not look like a CHIP device.
[1757438792.820] [45354:45355] [BLE] Device 27:03:71:07:51:35 does not look like a CHIP device.
[1757438792.825] [45354:45355] [BLE] Device 2B:42:50:00:43:2F does not look like a CHIP device.
[1757438792.827] [45354:45355] [BLE] Device 15:48:1A:A5:1C:34 does not look like a CHIP device.
[1757438792.831] [45354:45355] [BLE] Device 33:CE:4E:97:C2:75 does not look like a CHIP device.
[1757438792.833] [45354:45355] [BLE] Device 2B:70:04:BF:97:75 does not look like a CHIP device.
[1757438792.837] [45354:45355] [BLE] Device 1F:6C:DA:3F:49:5E does not look like a CHIP device.
[1757438792.866] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.866] [45354:45355] [BLE] Device 18:E1:60:F4:4B:CC does not look like a CHIP device.
[1757438792.867] [45354:45355] [BLE] Device 78:FC:34:64:56:61 does not look like a CHIP device.
[1757438792.874] [45354:45355] [BLE] Device 49:5C:89:2F:C9:5F does not look like a CHIP device.
[1757438792.876] [45354:45355] [BLE] Device 0F:08:AF:08:C1:78 does not look like a CHIP device.
[1757438792.877] [45354:45355] [BLE] Device 30:62:26:00:06:9D does not look like a CHIP device.
[1757438792.882] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.886] [45354:45355] [BLE] Device 4A:F1:25:EF:45:FF does not look like a CHIP device.
[1757438792.894] [45354:45355] [BLE] Device E4:FA:5B:9D:18:10 does not look like a CHIP device.
[1757438792.895] [45354:45355] [BLE] Device 26:41:38:2A:F6:B9 does not look like a CHIP device.
[1757438792.903] [45354:45355] [BLE] Device E4:FA:5B:9E:73:70 does not look like a CHIP device.
[1757438792.931] [45354:45355] [BLE] Device 6D:CC:FD:BF:5C:22 does not look like a CHIP device.
[1757438792.934] [45354:45355] [BLE] Device 16:CB:19:32:53:11 does not look like a CHIP device.
[1757438792.935] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438792.938] [45354:45355] [BLE] Device 33:CE:4E:97:C2:75 does not look like a CHIP device.
[1757438792.949] [45354:45355] [BLE] Device E4:FA:5B:9E:73:70 does not look like a CHIP device.
[1757438792.958] [45354:45355] [BLE] Device 43:66:97:54:A4:A2 does not look like a CHIP device.
[1757438792.961] [45354:45355] [BLE] Device 0E:FA:29:DE:88:A3 does not look like a CHIP device.
[1757438792.982] [45354:45355] [BLE] Device E4:FA:5B:9E:73:70 does not look like a CHIP device.
[1757438792.983] [45354:45355] [BLE] Device 30:62:26:00:06:9D does not look like a CHIP device.
[1757438792.996] [45354:45355] [BLE] Device 44:73:D6:DD:56:28 does not look like a CHIP device.
[1757438792.999] [45354:45355] [BLE] Device 26:41:38:2A:F6:B9 does not look like a CHIP device.
[1757438793.008] [45354:45355] [BLE] Device C6:91:6F:11:60:F4 does not look like a CHIP device.
[1757438793.009] [45354:45355] [BLE] Device 2D:02:46:F8:BA:3E does not look like a CHIP device.
[1757438793.012] [45354:45355] [BLE] Device 0C:67:EC:66:D1:43 does not look like a CHIP device.
[1757438793.017] [45354:45355] [BLE] Device 1C:1B:51:84:BA:5A does not look like a CHIP device.
[1757438793.023] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438793.027] [45354:45355] [BLE] Device 44:01:E0:9B:0A:27 does not look like a CHIP device.
[1757438793.034] [45354:45355] [BLE] Device 59:69:B7:22:6C:B0 does not look like a CHIP device.
[1757438793.034] [45354:45355] [BLE] Device 2B:42:50:00:43:2F does not look like a CHIP device.
[1757438793.037] [45354:45355] [BLE] Device 33:CE:4E:97:C2:75 does not look like a CHIP device.
[1757438793.043] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438793.045] [45354:45355] [BLE] Device 1F:6C:DA:3F:49:5E does not look like a CHIP device.
[1757438793.047] [45354:45355] [BLE] Device 14:E4:D3:E0:08:69 does not look like a CHIP device.
[1757438793.048] [45354:45355] [BLE] Device 78:FC:34:64:56:61 does not look like a CHIP device.
[1757438793.058] [45354:45355] [BLE] Device 75:45:23:16:4E:59 does not look like a CHIP device.
[1757438793.064] [45354:45355] [BLE] Device C6:91:6F:11:60:F4 does not look like a CHIP device.
[1757438793.065] [45354:45355] [BLE] Device 0E:FA:29:DE:88:A3 does not look like a CHIP device.
[1757438793.066] [45354:45355] [BLE] Device 1B:30:BF:51:CB:E3 does not look like a CHIP device.
[1757438793.072] [45354:45355] [BLE] Device E4:52:1E:14:79:66 does not look like a CHIP device.
[1757438793.078] [45354:45355] [BLE] Device 50:EA:97:3F:FF:06 does not look like a CHIP device.
[1757438793.081] [45354:45355] [BLE] Device 30:62:26:00:06:9D does not look like a CHIP device.
[1757438793.084] [45354:45355] [BLE] Device 0F:08:AF:08:C1:78 does not look like a CHIP device.
[1757438793.086] [45354:45355] [BLE] Device 2D:0C:D8:57:F8:72 does not look like a CHIP device.
[1757438793.091] [45354:45355] [BLE] Device 3C:21:D0:CF:47:F8 does not look like a CHIP device.
[1757438793.096] [45354:45355] [BLE] Device E4:FA:5B:9D:18:10 does not look like a CHIP device.
[1757438793.098] [45354:45355] [BLE] Device 39:95:A7:BD:E6:BC does not look like a CHIP device.
[1757438793.101] [45354:45355] [BLE] Device 43:44:9B:CC:9E:E5 does not look like a CHIP device.
[1757438793.108] [45354:45355] [BLE] Device 1D:0A:3F:40:D5:A1 does not look like a CHIP device.
[1757438793.113] [45354:45355] [BLE] Device 2D:02:46:F8:BA:3E does not look like a CHIP device.
[1757438793.122] [45354:45355] [BLE] Device 11:91:A4:B1:48:F1 does not look like a CHIP device.
[1757438793.124] [45354:45355] [BLE] Device 1C:1B:51:84:BA:5A does not look like a CHIP device.
[1757438793.131] [45354:45355] [BLE] New device scanned: DA:EB:1A:99:75:64
[1757438793.131] [45354:45355] [BLE] Device discriminator match. Attempting to connect.
[1757438793.134] [45354:45355] [BLE] ChipDeviceScanner has stopped scanning!
[1757438793.533] [45354:45355] [DL] ConnectDevice complete
[1757438793.533] [45354:45355] [BLE] New device connected: DA:EB:1A:99:75:64
[1757438794.415] [45354:45355] [DL] CHIP service found
[1757438794.415] [45354:45355] [DL] Valid C2 characteristic found
[1757438794.415] [45354:45355] [DL] Valid C1 characteristic found
[1757438794.415] [45354:45355] [DL] New BLE connection: conn=0x79bfb006ccf0 device=DA:EB:1A:99:75:64 path=/org/bluez/hci0/dev_DA_EB_1A_99_75_64
[1757438794.415] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16387
[1757438794.415] [45354:45356] [DIS] Closing all BLE connections
[1757438794.415] [45354:45356] [IN] BleConnectionComplete: endPoint 0x56845d27ad00
[1757438794.415] [45354:45356] [IN] SecureSession[0x79bfa800b4b0]: Allocated Type:1 LSID:37260
[1757438794.415] [45354:45356] [SC] Assigned local session key ID 37260
[1757438794.415] [45354:45356] [EM] <<< [E:54425i S:0 M:123803580] (U) Msg TX from 2A81D60EC0236D4B to 0:0000000000000000 [0000] [BLE] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98)
[1757438794.415] [45354:45356] [IN] Message appended to BLE send queue
[1757438794.415] [45354:45356] [SC] Sent PBKDF param request [II:500ms AI:300ms AT:4000ms)
[1757438794.929] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438795.020] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16390
[1757438795.020] [45354:45356] [BLE] subscribe complete, ep = 0x56845d27ad00
[1757438795.020] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438795.020] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438795.020] [45354:45356] [BLE] peripheral chose BTP version 4; central expected between 4 and 4
[1757438795.020] [45354:45356] [BLE] using BTP fragment sizes rx 244 / tx 244.
[1757438795.020] [45354:45356] [BLE] local and remote recv window size = 5
[1757438795.020] [45354:45356] [IN] BLE EndPoint 0x56845d27ad00 Connection Complete
[1757438795.109] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438795.156] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438795.156] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438795.156] [45354:45356] [EM] >>> [E:54425i S:0 M:57345423] (U) Msg RX from 0:0000000000000000 [0000] to 2A81D60EC0236D4B --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154)
[1757438795.156] [45354:45356] [EM] Found matching exchange: 54425i, Delegate: 0x79bfa800c168
[1757438795.156] [45354:45356] [SC] Received PBKDF param response
[1757438795.156] [45354:45356] [SC] Peer assigned session ID 6167
[1757438795.156] [45354:45356] [SC] Found MRP parameters in the message
[1757438795.164] [45354:45356] [EM] <<< [E:54425i S:0 M:123803581] (U) Msg TX from 2A81D60EC0236D4B to 0:0000000000000000 [0000] [BLE] --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92)
[1757438795.165] [45354:45356] [SC] Sent spake2p msg1
[1757438795.289] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438795.426] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438795.426] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438795.426] [45354:45356] [EM] >>> [E:54425i S:0 M:57345424] (U) Msg RX from 0:0000000000000000 [0000] to 2A81D60EC0236D4B --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127)
[1757438795.426] [45354:45356] [EM] Found matching exchange: 54425i, Delegate: 0x79bfa800c168
[1757438795.426] [45354:45356] [SC] Received spake2p msg2
[1757438795.434] [45354:45356] [EM] <<< [E:54425i S:0 M:123803582] (U) Msg TX from 2A81D60EC0236D4B to 0:0000000000000000 [0000] [BLE] --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59)
[1757438795.434] [45354:45356] [SC] Sent spake2p msg3
[1757438795.514] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438795.560] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438795.560] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438795.560] [45354:45356] [EM] >>> [E:54425i S:0 M:57345425] (U) Msg RX from 0:0000000000000000 [0000] to 2A81D60EC0236D4B --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
[1757438795.560] [45354:45356] [EM] Found matching exchange: 54425i, Delegate: 0x79bfa800c168
[1757438795.560] [45354:45356] [SC] SecureSession[0x79bfa800b4b0, LSID:37260]: State change 'kEstablishing' --> 'kActive'
[1757438795.560] [45354:45356] [IN] SecureSession[0x79bfa800b4b0]: Activated - Type:1 LSID:37260
[1757438795.560] [45354:45356] [IN] New secure session activated for device <FFFFFFFB00000000, 0>, LSID:37260 PSID:6167!
[1757438795.560] [45354:45356] [CTL] Remote device completed SPAKE2+ handshake
[1757438795.560] [45354:45356] [TOO] Pairing Success
[1757438795.560] [45354:45356] [TOO] PASE establishment successful
[1757438795.560] [45354:45356] [CTL] Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1757438795.560] [45354:45356] [CTL] Performing next commissioning step 'ReadCommissioningInfo'
[1757438795.560] [45354:45356] [CTL] Sending read requests for commissioning information
[1757438795.560] [45354:45356] [DMG] SendReadRequest ReadClient[0x79bfa800dba0]: Sending Read Request
[1757438795.560] [45354:45356] [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
[1757438795.560] [45354:45356] [EM] <<< [E:54426i S:37260 M:199337710] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:02 (IM:ReadRequest) (B:134)
[1757438795.560] [45354:45356] [DMG] MoveToState ReadClient[0x79bfa800dba0]: Moving to [AwaitingIn]
[1757438795.561] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 32792
[1757438795.649] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438795.697] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438795.697] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438795.784] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438795.784] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438795.785] [45354:45356] [EM] >>> [E:54426i S:37260 M:192540095] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:05 (IM:ReportData) (B:257)
[1757438795.785] [45354:45356] [EM] Found matching exchange: 54426i, Delegate: 0x79bfa800dbb0
[1757438795.785] [45354:45356] [DMG] ReportDataMessage =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] AttributeReportIBs =
[1757438795.785] [45354:45356] [DMG] [
[1757438795.785] [45354:45356] [DMG] AttributeReportIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] AttributeDataIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] DataVersion = 0xa4a9506d,
[1757438795.785] [45354:45356] [DMG] AttributePathIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] Endpoint = 0x0,
[1757438795.785] [45354:45356] [DMG] Cluster = 0x31,
[1757438795.785] [45354:45356] [DMG] Attribute = 0x0000_FFFC,
[1757438795.785] [45354:45356] [DMG] }
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] Data = 2 (unsigned),
[1757438795.785] [45354:45356] [DMG] },
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] },
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] AttributeReportIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] AttributeDataIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] DataVersion = 0x38b55960,
[1757438795.785] [45354:45356] [DMG] AttributePathIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] Endpoint = 0x0,
[1757438795.785] [45354:45356] [DMG] Cluster = 0x28,
[1757438795.785] [45354:45356] [DMG] Attribute = 0x0000_0004,
[1757438795.785] [45354:45356] [DMG] }
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] Data = 32773 (unsigned),
[1757438795.785] [45354:45356] [DMG] },
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] },
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] AttributeReportIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] AttributeDataIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] DataVersion = 0x38b55960,
[1757438795.785] [45354:45356] [DMG] AttributePathIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] Endpoint = 0x0,
[1757438795.785] [45354:45356] [DMG] Cluster = 0x28,
[1757438795.785] [45354:45356] [DMG] Attribute = 0x0000_0002,
[1757438795.785] [45354:45356] [DMG] }
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] Data = 65521 (unsigned),
[1757438795.785] [45354:45356] [DMG] },
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] },
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] AttributeReportIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] AttributeDataIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] DataVersion = 0xdd13970d,
[1757438795.785] [45354:45356] [DMG] AttributePathIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] Endpoint = 0x0,
[1757438795.785] [45354:45356] [DMG] Cluster = 0x30,
[1757438795.785] [45354:45356] [DMG] Attribute = 0x0000_0003,
[1757438795.785] [45354:45356] [DMG] }
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] Data = 0 (unsigned),
[1757438795.785] [45354:45356] [DMG] },
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] },
[1757438795.785] [45354:45356] [DMG]
[1757438795.785] [45354:45356] [DMG] AttributeReportIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] AttributeDataIB =
[1757438795.785] [45354:45356] [DMG] {
[1757438795.785] [45354:45356] [DMG] DataVersion = 0xdd13970d,
[1757438795.786] [45354:45356] [DMG] AttributePathIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] Endpoint = 0x0,
[1757438795.786] [45354:45356] [DMG] Cluster = 0x30,
[1757438795.786] [45354:45356] [DMG] Attribute = 0x0000_0002,
[1757438795.786] [45354:45356] [DMG] }
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] Data = 0 (unsigned),
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] AttributeReportIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] AttributeDataIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] DataVersion = 0xdd13970d,
[1757438795.786] [45354:45356] [DMG] AttributePathIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] Endpoint = 0x0,
[1757438795.786] [45354:45356] [DMG] Cluster = 0x30,
[1757438795.786] [45354:45356] [DMG] Attribute = 0x0000_0001,
[1757438795.786] [45354:45356] [DMG] }
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] Data =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] 0x0 = 60 (unsigned),
[1757438795.786] [45354:45356] [DMG] 0x1 = 900 (unsigned),
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] AttributeReportIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] AttributeDataIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] DataVersion = 0xdd13970d,
[1757438795.786] [45354:45356] [DMG] AttributePathIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] Endpoint = 0x0,
[1757438795.786] [45354:45356] [DMG] Cluster = 0x30,
[1757438795.786] [45354:45356] [DMG] Attribute = 0x0000_0000,
[1757438795.786] [45354:45356] [DMG] }
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] Data = 0 (unsigned),
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] AttributeReportIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] AttributeDataIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] DataVersion = 0xdd13970d,
[1757438795.786] [45354:45356] [DMG] AttributePathIB =
[1757438795.786] [45354:45356] [DMG] {
[1757438795.786] [45354:45356] [DMG] Endpoint = 0x0,
[1757438795.786] [45354:45356] [DMG] Cluster = 0x30,
[1757438795.786] [45354:45356] [DMG] Attribute = 0x0000_0004,
[1757438795.786] [45354:45356] [DMG] }
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] Data = true,
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] },
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] ],
[1757438795.786] [45354:45356] [DMG]
[1757438795.786] [45354:45356] [DMG] SuppressResponse = true,
[1757438795.786] [45354:45356] [DMG] InteractionModelRevision = 12
[1757438795.786] [45354:45356] [DMG] }
[1757438795.787] [45354:45356] [DMG] SendReadRequest ReadClient[0x79bfa800dba0]: Sending Read Request
[1757438795.787] [45354:45356] [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
[1757438795.787] [45354:45356] [EM] <<< [E:54427i S:37260 M:199337711] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:02 (IM:ReadRequest) (B:103)
[1757438795.787] [45354:45356] [DMG] MoveToState ReadClient[0x79bfa800dba0]: Moving to [AwaitingIn]
[1757438795.874] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438796.013] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438796.013] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438796.013] [45354:45356] [EM] >>> [E:54427i S:37260 M:192540096] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:05 (IM:ReportData) (B:181)
[1757438796.013] [45354:45356] [EM] Found matching exchange: 54427i, Delegate: 0x79bfa800dbb0
[1757438796.013] [45354:45356] [DMG] ReportDataMessage =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] AttributeReportIBs =
[1757438796.013] [45354:45356] [DMG] [
[1757438796.013] [45354:45356] [DMG] AttributeReportIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] AttributeStatusIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] AttributePathIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] Endpoint = 0x0,
[1757438796.013] [45354:45356] [DMG] Cluster = 0x46,
[1757438796.013] [45354:45356] [DMG] Attribute = 0x0000_0002,
[1757438796.013] [45354:45356] [DMG] }
[1757438796.013] [45354:45356] [DMG]
[1757438796.013] [45354:45356] [DMG] StatusIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] status = 0xc3 (UNSUPPORTED_CLUSTER),
[1757438796.013] [45354:45356] [DMG] },
[1757438796.013] [45354:45356] [DMG]
[1757438796.013] [45354:45356] [DMG] },
[1757438796.013] [45354:45356] [DMG]
[1757438796.013] [45354:45356] [DMG] },
[1757438796.013] [45354:45356] [DMG]
[1757438796.013] [45354:45356] [DMG] AttributeReportIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] AttributeStatusIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] AttributePathIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] Endpoint = 0x0,
[1757438796.013] [45354:45356] [DMG] Cluster = 0x46,
[1757438796.013] [45354:45356] [DMG] Attribute = 0x0000_0001,
[1757438796.013] [45354:45356] [DMG] }
[1757438796.013] [45354:45356] [DMG]
[1757438796.013] [45354:45356] [DMG] StatusIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] status = 0xc3 (UNSUPPORTED_CLUSTER),
[1757438796.013] [45354:45356] [DMG] },
[1757438796.013] [45354:45356] [DMG]
[1757438796.013] [45354:45356] [DMG] },
[1757438796.013] [45354:45356] [DMG]
[1757438796.013] [45354:45356] [DMG] },
[1757438796.013] [45354:45356] [DMG]
[1757438796.013] [45354:45356] [DMG] AttributeReportIB =
[1757438796.013] [45354:45356] [DMG] {
[1757438796.013] [45354:45356] [DMG] AttributeStatusIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] AttributePathIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] Endpoint = 0x0,
[1757438796.014] [45354:45356] [DMG] Cluster = 0x46,
[1757438796.014] [45354:45356] [DMG] Attribute = 0x0000_0000,
[1757438796.014] [45354:45356] [DMG] }
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] StatusIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] status = 0xc3 (UNSUPPORTED_CLUSTER),
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] AttributeReportIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] AttributeStatusIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] AttributePathIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] Endpoint = 0x0,
[1757438796.014] [45354:45356] [DMG] Cluster = 0x46,
[1757438796.014] [45354:45356] [DMG] Attribute = 0x0000_0007,
[1757438796.014] [45354:45356] [DMG] }
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] StatusIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] status = 0xc3 (UNSUPPORTED_CLUSTER),
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] AttributeReportIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] AttributeStatusIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] AttributePathIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] Endpoint = 0x0,
[1757438796.014] [45354:45356] [DMG] Cluster = 0x46,
[1757438796.014] [45354:45356] [DMG] Attribute = 0x0000_0006,
[1757438796.014] [45354:45356] [DMG] }
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] StatusIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] status = 0xc3 (UNSUPPORTED_CLUSTER),
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] },
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] AttributeReportIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] AttributeDataIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] DataVersion = 0xa4a9506d,
[1757438796.014] [45354:45356] [DMG] AttributePathIB =
[1757438796.014] [45354:45356] [DMG] {
[1757438796.014] [45354:45356] [DMG] Endpoint = 0x0,
[1757438796.014] [45354:45356] [DMG] Cluster = 0x31,
[1757438796.014] [45354:45356] [DMG] Attribute = 0x0000_0003,
[1757438796.014] [45354:45356] [DMG] }
[1757438796.014] [45354:45356] [DMG]
[1757438796.014] [45354:45356] [DMG] Data = 20 (unsigned),
[1757438796.014] [45354:45356] [DMG] },
[1757438796.015] [45354:45356] [DMG]
[1757438796.015] [45354:45356] [DMG] },
[1757438796.015] [45354:45356] [DMG]
[1757438796.015] [45354:45356] [DMG] ],
[1757438796.015] [45354:45356] [DMG]
[1757438796.015] [45354:45356] [DMG] SuppressResponse = true,
[1757438796.015] [45354:45356] [DMG] InteractionModelRevision = 12
[1757438796.015] [45354:45356] [DMG] }
[1757438796.015] [45354:45356] [CTL] NetworkCommissioning Features: has Thread. endpointid = 0
[1757438796.015] [45354:45356] [SVR] OnReadCommissioningInfo - vendorId=0xFFF1 productId=0x8005
[1757438796.015] [45354:45356] [SVR] OnReadCommissioningInfo ICD - IdleModeDuration=0 activeModeDuration=0 activeModeThreshold=0
[1757438796.015] [45354:45356] [CTL] Successfully finished commissioning step 'ReadCommissioningInfo'
[1757438796.015] [45354:45356] [CTL] Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe'
[1757438796.015] [45354:45356] [CTL] Performing next commissioning step 'ArmFailSafe'
[1757438796.015] [45354:45356] [CTL] Arming failsafe (60 seconds)
[1757438796.015] [45354:45356] [DMG] ICR moving to [AddingComm]
[1757438796.015] [45354:45356] [DMG] ICR moving to [AddedComma]
[1757438796.015] [45354:45356] [EM] <<< [E:54428i S:37260 M:199337712] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
[1757438796.015] [45354:45356] [DMG] ICR moving to [AwaitingRe]
[1757438796.189] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438796.234] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438796.234] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438796.234] [45354:45356] [EM] >>> [E:54428i S:37260 M:192540097] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1757438796.235] [45354:45356] [EM] Found matching exchange: 54428i, Delegate: 0x79bfa80060e8
[1757438796.235] [45354:45356] [DMG] ICR moving to [ResponseRe]
[1757438796.235] [45354:45356] [DMG] InvokeResponseMessage =
[1757438796.235] [45354:45356] [DMG] {
[1757438796.235] [45354:45356] [DMG] suppressResponse = false,
[1757438796.235] [45354:45356] [DMG] InvokeResponseIBs =
[1757438796.235] [45354:45356] [DMG] [
[1757438796.235] [45354:45356] [DMG] InvokeResponseIB =
[1757438796.235] [45354:45356] [DMG] {
[1757438796.235] [45354:45356] [DMG] CommandDataIB =
[1757438796.235] [45354:45356] [DMG] {
[1757438796.235] [45354:45356] [DMG] CommandPathIB =
[1757438796.235] [45354:45356] [DMG] {
[1757438796.235] [45354:45356] [DMG] EndpointId = 0x0,
[1757438796.235] [45354:45356] [DMG] ClusterId = 0x30,
[1757438796.235] [45354:45356] [DMG] CommandId = 0x1,
[1757438796.235] [45354:45356] [DMG] },
[1757438796.235] [45354:45356] [DMG]
[1757438796.235] [45354:45356] [DMG] CommandFields =
[1757438796.235] [45354:45356] [DMG] {
[1757438796.235] [45354:45356] [DMG] 0x0 = 0 (unsigned),
[1757438796.235] [45354:45356] [DMG] 0x1 = "" (0 chars),
[1757438796.235] [45354:45356] [DMG] },
[1757438796.235] [45354:45356] [DMG] },
[1757438796.235] [45354:45356] [DMG]
[1757438796.235] [45354:45356] [DMG] },
[1757438796.235] [45354:45356] [DMG]
[1757438796.235] [45354:45356] [DMG] ],
[1757438796.235] [45354:45356] [DMG]
[1757438796.235] [45354:45356] [DMG] InteractionModelRevision = 12
[1757438796.235] [45354:45356] [DMG] },
[1757438796.235] [45354:45356] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1757438796.235] [45354:45356] [CTL] Received ArmFailSafe response errorCode=0
[1757438796.235] [45354:45356] [CTL] Successfully finished commissioning step 'ArmFailSafe'
[1757438796.235] [45354:45356] [CTL] Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1757438796.235] [45354:45356] [CTL] Performing next commissioning step 'ConfigRegulatory'
[1757438796.235] [45354:45356] [CTL] Setting Regulatory Config
[1757438796.235] [45354:45356] [CTL] Device does not support configurable regulatory location
[1757438796.235] [45354:45356] [DMG] ICR moving to [AddingComm]
[1757438796.235] [45354:45356] [DMG] ICR moving to [AddedComma]
[1757438796.235] [45354:45356] [EM] <<< [E:54429i S:37260 M:199337713] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:70)
[1757438796.235] [45354:45356] [DMG] ICR moving to [AwaitingRe]
[1757438796.235] [45354:45356] [DMG] ICR moving to [AwaitingDe]
[1757438796.324] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438796.369] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438796.370] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438796.370] [45354:45356] [EM] >>> [E:54429i S:37260 M:192540098] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1757438796.370] [45354:45356] [EM] Found matching exchange: 54429i, Delegate: 0x79bfa8006298
[1757438796.370] [45354:45356] [DMG] ICR moving to [ResponseRe]
[1757438796.370] [45354:45356] [DMG] InvokeResponseMessage =
[1757438796.370] [45354:45356] [DMG] {
[1757438796.370] [45354:45356] [DMG] suppressResponse = false,
[1757438796.370] [45354:45356] [DMG] InvokeResponseIBs =
[1757438796.370] [45354:45356] [DMG] [
[1757438796.370] [45354:45356] [DMG] InvokeResponseIB =
[1757438796.370] [45354:45356] [DMG] {
[1757438796.370] [45354:45356] [DMG] CommandDataIB =
[1757438796.370] [45354:45356] [DMG] {
[1757438796.370] [45354:45356] [DMG] CommandPathIB =
[1757438796.370] [45354:45356] [DMG] {
[1757438796.370] [45354:45356] [DMG] EndpointId = 0x0,
[1757438796.370] [45354:45356] [DMG] ClusterId = 0x30,
[1757438796.370] [45354:45356] [DMG] CommandId = 0x3,
[1757438796.370] [45354:45356] [DMG] },
[1757438796.370] [45354:45356] [DMG]
[1757438796.370] [45354:45356] [DMG] CommandFields =
[1757438796.370] [45354:45356] [DMG] {
[1757438796.370] [45354:45356] [DMG] 0x0 = 0 (unsigned),
[1757438796.370] [45354:45356] [DMG] 0x1 = "" (0 chars),
[1757438796.370] [45354:45356] [DMG] },
[1757438796.370] [45354:45356] [DMG] },
[1757438796.370] [45354:45356] [DMG]
[1757438796.370] [45354:45356] [DMG] },
[1757438796.370] [45354:45356] [DMG]
[1757438796.370] [45354:45356] [DMG] ],
[1757438796.370] [45354:45356] [DMG]
[1757438796.370] [45354:45356] [DMG] InteractionModelRevision = 12
[1757438796.370] [45354:45356] [DMG] },
[1757438796.370] [45354:45356] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1757438796.370] [45354:45356] [CTL] Received SetRegulatoryConfig response errorCode=0
[1757438796.370] [45354:45356] [CTL] Successfully finished commissioning step 'ConfigRegulatory'
[1757438796.370] [45354:45356] [CTL] Commissioning stage next step: 'ConfigRegulatory' -> 'ConfigureTCAcknowledgments'
[1757438796.370] [45354:45356] [CTL] Performing next commissioning step 'ConfigureTCAcknowledgments'
[1757438796.370] [45354:45356] [CTL] Setting Terms and Conditions
[1757438796.370] [45354:45356] [CTL] Setting Terms and Conditions: Skipped
[1757438796.370] [45354:45356] [CTL] Successfully finished commissioning step 'ConfigureTCAcknowledgments'
[1757438796.370] [45354:45356] [CTL] Commissioning stage next step: 'ConfigureTCAcknowledgments' -> 'SendPAICertificateRequest'
[1757438796.370] [45354:45356] [CTL] Performing next commissioning step 'SendPAICertificateRequest'
[1757438796.370] [45354:45356] [CTL] Sending request for PAI certificate
[1757438796.370] [45354:45356] [CTL] Sending Certificate Chain request to 0x79bfa800c110 device
[1757438796.370] [45354:45356] [DMG] ICR moving to [AddingComm]
[1757438796.370] [45354:45356] [DMG] ICR moving to [AddedComma]
[1757438796.370] [45354:45356] [EM] <<< [E:54430i S:37260 M:199337714] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[1757438796.370] [45354:45356] [DMG] ICR moving to [AwaitingRe]
[1757438796.370] [45354:45356] [DMG] ICR moving to [AwaitingDe]
[1757438796.459] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438796.507] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438796.507] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438796.596] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438796.596] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438796.685] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438796.685] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438796.685] [45354:45356] [EM] >>> [E:54430i S:37260 M:192540099] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:527)
[1757438796.685] [45354:45356] [EM] Found matching exchange: 54430i, Delegate: 0x79bfa80060e8
[1757438796.685] [45354:45356] [DMG] ICR moving to [ResponseRe]
[1757438796.685] [45354:45356] [DMG] InvokeResponseMessage =
[1757438796.685] [45354:45356] [DMG] {
[1757438796.685] [45354:45356] [DMG] suppressResponse = false,
[1757438796.685] [45354:45356] [DMG] InvokeResponseIBs =
[1757438796.685] [45354:45356] [DMG] [
[1757438796.685] [45354:45356] [DMG] InvokeResponseIB =
[1757438796.685] [45354:45356] [DMG] {
[1757438796.685] [45354:45356] [DMG] CommandDataIB =
[1757438796.685] [45354:45356] [DMG] {
[1757438796.685] [45354:45356] [DMG] CommandPathIB =
[1757438796.685] [45354:45356] [DMG] {
[1757438796.685] [45354:45356] [DMG] EndpointId = 0x0,
[1757438796.685] [45354:45356] [DMG] ClusterId = 0x3e,
[1757438796.685] [45354:45356] [DMG] CommandId = 0x3,
[1757438796.685] [45354:45356] [DMG] },
[1757438796.685] [45354:45356] [DMG]
[1757438796.685] [45354:45356] [DMG] CommandFields =
[1757438796.685] [45354:45356] [DMG] {
[1757438796.685] [45354:45356] [DMG] 0x0 = [
[1757438796.685] [45354:45356] [DMG] 0x30, 0x82, 0x01, 0xcb, 0x30, 0x82, 0x01, 0x71, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x56, 0xad, 0x82, 0x22, 0xad, 0x94, 0x5b, 0x64, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x30, 0x31, 0x18, 0x30, 0x16, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x0f, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x54, 0x65, 0x73, 0x74, 0x20, 0x50, 0x41, 0x41, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x41, 0x9a, 0x93, 0x15, 0xc2, 0x17, 0x3e, 0x0c, 0x8c, 0x87, 0x6d, 0x03, 0xcc, 0xfc, 0x94, 0x48, 0x52, 0x64, 0x7f, 0x7f, 0xec, 0x5e, 0x50, 0x82, 0xf4, 0x05, 0x99, 0x28, 0xec, 0xa8, 0x94, 0xc5, 0x94, 0x15, 0x13, 0x09, 0xac, 0x63, 0x1e, 0x4c, 0xb0, 0x33, 0x92, 0xaf, 0x68, 0x4b, 0x0b, 0xaf, 0xb7, 0xe6, 0x5b, 0x3b, 0x81, 0x62, 0xc2, 0xf5, 0x2b, 0xf9, 0x31, 0xb8, 0xe7, 0x7a, 0xaa, 0x82, 0xa3, 0x66, 0x30, 0x64, 0x30, 0x12, 0x06, 0x03, 0x55, 0x1d, 0x
[1757438796.685] [45354:45356] [DMG] ] (463 bytes)
[1757438796.685] [45354:45356] [DMG] },
[1757438796.685] [45354:45356] [DMG] },
[1757438796.685] [45354:45356] [DMG]
[1757438796.685] [45354:45356] [DMG] },
[1757438796.685] [45354:45356] [DMG]
[1757438796.685] [45354:45356] [DMG] ],
[1757438796.685] [45354:45356] [DMG]
[1757438796.685] [45354:45356] [DMG] InteractionModelRevision = 12
[1757438796.685] [45354:45356] [DMG] },
[1757438796.685] [45354:45356] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1757438796.685] [45354:45356] [CTL] Received certificate chain from the device
[1757438796.685] [45354:45356] [CTL] Successfully finished commissioning step 'SendPAICertificateRequest'
[1757438796.685] [45354:45356] [CTL] Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1757438796.685] [45354:45356] [CTL] Performing next commissioning step 'SendDACCertificateRequest'
[1757438796.685] [45354:45356] [CTL] Sending request for DAC certificate
[1757438796.685] [45354:45356] [CTL] Sending Certificate Chain request to 0x79bfa800c110 device
[1757438796.685] [45354:45356] [DMG] ICR moving to [AddingComm]
[1757438796.685] [45354:45356] [DMG] ICR moving to [AddedComma]
[1757438796.685] [45354:45356] [EM] <<< [E:54431i S:37260 M:199337715] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[1757438796.686] [45354:45356] [DMG] ICR moving to [AwaitingRe]
[1757438796.686] [45354:45356] [DMG] ICR moving to [AwaitingDe]
[1757438796.774] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438796.821] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438796.821] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438796.911] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438796.911] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438796.999] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438797.000] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438797.000] [45354:45356] [EM] >>> [E:54431i S:37260 M:192540100] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:556)
[1757438797.000] [45354:45356] [EM] Found matching exchange: 54431i, Delegate: 0x79bfa8006298
[1757438797.000] [45354:45356] [DMG] ICR moving to [ResponseRe]
[1757438797.000] [45354:45356] [DMG] InvokeResponseMessage =
[1757438797.000] [45354:45356] [DMG] {
[1757438797.000] [45354:45356] [DMG] suppressResponse = false,
[1757438797.000] [45354:45356] [DMG] InvokeResponseIBs =
[1757438797.000] [45354:45356] [DMG] [
[1757438797.000] [45354:45356] [DMG] InvokeResponseIB =
[1757438797.000] [45354:45356] [DMG] {
[1757438797.000] [45354:45356] [DMG] CommandDataIB =
[1757438797.000] [45354:45356] [DMG] {
[1757438797.000] [45354:45356] [DMG] CommandPathIB =
[1757438797.000] [45354:45356] [DMG] {
[1757438797.000] [45354:45356] [DMG] EndpointId = 0x0,
[1757438797.000] [45354:45356] [DMG] ClusterId = 0x3e,
[1757438797.000] [45354:45356] [DMG] CommandId = 0x3,
[1757438797.000] [45354:45356] [DMG] },
[1757438797.000] [45354:45356] [DMG]
[1757438797.000] [45354:45356] [DMG] CommandFields =
[1757438797.000] [45354:45356] [DMG] {
[1757438797.000] [45354:45356] [DMG] 0x0 = [
[1757438797.000] [45354:45356] [DMG] 0x30, 0x82, 0x01, 0xe8, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x6f, 0xdc, 0xb6, 0xed, 0x06, 0xf3, 0x58, 0xf9, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x53, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x44, 0x41, 0x43, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x2f, 0x30, 0x78, 0x38, 0x30, 0x30, 0x35, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x02, 0x0c, 0x04, 0x38, 0x30, 0x30, 0x35, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x7e, 0xf2, 0xf1, 0x08, 0x2b, 0x2a, 0x56, 0x4a, 0x05, 0x44, 0xc0, 0xa6, 0x13, 0xd2, 0x1b, 0x15, 0x75, 0x00, 0x55, 0x2d, 0x03, 0x5f, 0x23, 0x02, 0x25, 0x2f, 0xce, 0xe8, 0x1d, 0x6e, 0xc6, 0x74, 0x17, 0x34, 0x18, 0xa9, 0x4a, 0x88, 0xdb, 0x
[1757438797.000] [45354:45356] [DMG] ] (492 bytes)
[1757438797.000] [45354:45356] [DMG] },
[1757438797.000] [45354:45356] [DMG] },
[1757438797.000] [45354:45356] [DMG]
[1757438797.000] [45354:45356] [DMG] },
[1757438797.000] [45354:45356] [DMG]
[1757438797.000] [45354:45356] [DMG] ],
[1757438797.000] [45354:45356] [DMG]
[1757438797.000] [45354:45356] [DMG] InteractionModelRevision = 12
[1757438797.000] [45354:45356] [DMG] },
[1757438797.000] [45354:45356] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1757438797.000] [45354:45356] [CTL] Received certificate chain from the device
[1757438797.000] [45354:45356] [CTL] Successfully finished commissioning step 'SendDACCertificateRequest'
[1757438797.000] [45354:45356] [CTL] Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1757438797.000] [45354:45356] [CTL] Performing next commissioning step 'SendAttestationRequest'
[1757438797.000] [45354:45356] [CTL] Sending Attestation Request to the device.
[1757438797.000] [45354:45356] [CTL] Sending Attestation request to 0x79bfa800c110 device
[1757438797.000] [45354:45356] [DMG] ICR moving to [AddingComm]
[1757438797.000] [45354:45356] [DMG] ICR moving to [AddedComma]
[1757438797.000] [45354:45356] [EM] <<< [E:54432i S:37260 M:199337716] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
[1757438797.000] [45354:45356] [DMG] ICR moving to [AwaitingRe]
[1757438797.000] [45354:45356] [CTL] Sent Attestation request, waiting for the Attestation Information
[1757438797.000] [45354:45356] [DMG] ICR moving to [AwaitingDe]
[1757438797.089] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438797.181] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438797.182] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438797.271] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438797.271] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438797.361] [45354:45355] [DL] Indication received, conn = 0x79bfb006ccf0
[1757438797.361] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16391
[1757438797.362] [45354:45356] [EM] >>> [E:54432i S:37260 M:192540101] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:716)
[1757438797.362] [45354:45356] [EM] Found matching exchange: 54432i, Delegate: 0x79bfa80060e8
[1757438797.362] [45354:45356] [DMG] ICR moving to [ResponseRe]
[1757438797.362] [45354:45356] [DMG] InvokeResponseMessage =
[1757438797.362] [45354:45356] [DMG] {
[1757438797.362] [45354:45356] [DMG] suppressResponse = false,
[1757438797.362] [45354:45356] [DMG] InvokeResponseIBs =
[1757438797.362] [45354:45356] [DMG] [
[1757438797.362] [45354:45356] [DMG] InvokeResponseIB =
[1757438797.362] [45354:45356] [DMG] {
[1757438797.362] [45354:45356] [DMG] CommandDataIB =
[1757438797.362] [45354:45356] [DMG] {
[1757438797.362] [45354:45356] [DMG] CommandPathIB =
[1757438797.362] [45354:45356] [DMG] {
[1757438797.362] [45354:45356] [DMG] EndpointId = 0x0,
[1757438797.362] [45354:45356] [DMG] ClusterId = 0x3e,
[1757438797.362] [45354:45356] [DMG] CommandId = 0x1,
[1757438797.362] [45354:45356] [DMG] },
[1757438797.362] [45354:45356] [DMG]
[1757438797.362] [45354:45356] [DMG] CommandFields =
[1757438797.362] [45354:45356] [DMG] {
[1757438797.362] [45354:45356] [DMG] 0x0 = [
[1757438797.362] [45354:45356] [DMG] 0x15, 0x31, 0x01, 0x1d, 0x02, 0x30, 0x82, 0x02, 0x19, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x82, 0x02, 0x0a, 0x30, 0x82, 0x02, 0x06, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x82, 0x01, 0x71, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x82, 0x01, 0x62, 0x04, 0x82, 0x01, 0x5e, 0x15, 0x24, 0x00, 0x01, 0x25, 0x01, 0xf1, 0xff, 0x36, 0x02, 0x05, 0x00, 0x80, 0x05, 0x01, 0x80, 0x05, 0x02, 0x80, 0x05, 0x03, 0x80, 0x05, 0x04, 0x80, 0x05, 0x05, 0x80, 0x05, 0x06, 0x80, 0x05, 0x07, 0x80, 0x05, 0x08, 0x80, 0x05, 0x09, 0x80, 0x05, 0x0a, 0x80, 0x05, 0x0b, 0x80, 0x05, 0x0c, 0x80, 0x05, 0x0d, 0x80, 0x05, 0x0e, 0x80, 0x05, 0x0f, 0x80, 0x05, 0x10, 0x80, 0x05, 0x11, 0x80, 0x05, 0x12, 0x80, 0x05, 0x13, 0x80, 0x05, 0x14, 0x80, 0x05, 0x15, 0x80, 0x05, 0x16, 0x80, 0x05, 0x17, 0x80, 0x05, 0x18, 0x80, 0x05, 0x19, 0x80, 0x05, 0x1a, 0x80, 0x05, 0x1b, 0x80, 0x05, 0x1c, 0x80, 0x05, 0x1d, 0x80, 0x05, 0x1e, 0x80, 0x05, 0x1f, 0x80, 0x05, 0x20, 0x80, 0x05, 0x21, 0x80, 0x05, 0x22, 0x80, 0x05, 0x23, 0x80, 0x05, 0x24, 0x80, 0x05, 0x25, 0x80, 0x05, 0x26, 0x80, 0x05, 0x27, 0x80, 0x05, 0x28, 0x80, 0x05, 0x29, 0x80, 0x05, 0x2a, 0x80, 0x05, 0x2b, 0x80, 0x05, 0x2c, 0x80, 0x05, 0x2d, 0x80, 0x05, 0x2e, 0x80, 0x05, 0x2f, 0x80, 0x05, 0x30, 0x80, 0x05, 0x31, 0x80, 0x05, 0x32, 0x80, 0x05, 0x33, 0x80, 0x05, 0x34, 0x80, 0x05, 0x35, 0x80, 0x05, 0x36, 0x80, 0x05, 0x37, 0x80, 0x05, 0x38, 0x80, 0x05, 0x39, 0x80, 0x05, 0x3a, 0x80, 0x05, 0x3b, 0x80, 0x05, 0x3c, 0x80, 0x05, 0x3d, 0x80, 0x05, 0x3e, 0x80, 0x05, 0x3f, 0x80, 0x05, 0x40, 0x80, 0x05, 0x41, 0x80, 0x05, 0x42, 0x80, 0x05, 0x43, 0x80, 0x
[1757438797.362] [45354:45356] [DMG] ] (585 bytes)
[1757438797.362] [45354:45356] [DMG] 0x1 = [
[1757438797.362] [45354:45356] [DMG] 0x54, 0x4b, 0x6e, 0x28, 0xae, 0xac, 0xae, 0x1d, 0x2d, 0x99, 0xfd, 0xa7, 0x9a, 0xac, 0x64, 0xc9, 0x31, 0x90, 0x58, 0x56, 0x5b, 0x0b, 0xd7, 0x67, 0x2c, 0x51, 0xf5, 0x34, 0x74, 0x6e, 0xf1, 0xce, 0x05, 0xc6, 0xc9, 0xc8, 0x81, 0x4d, 0x5d, 0x4c, 0x69, 0xf2, 0xc6, 0x93, 0xf2, 0x42, 0x50, 0xa7, 0xd9, 0xda, 0x52, 0x4f, 0x36, 0x6b, 0x01, 0x45, 0xca, 0xe4, 0xee, 0x56, 0x18, 0x4a, 0xee, 0x86,
[1757438797.362] [45354:45356] [DMG] ] (64 bytes)
[1757438797.362] [45354:45356] [DMG] },
[1757438797.362] [45354:45356] [DMG] },
[1757438797.362] [45354:45356] [DMG]
[1757438797.362] [45354:45356] [DMG] },
[1757438797.362] [45354:45356] [DMG]
[1757438797.362] [45354:45356] [DMG] ],
[1757438797.362] [45354:45356] [DMG]
[1757438797.362] [45354:45356] [DMG] InteractionModelRevision = 12
[1757438797.362] [45354:45356] [DMG] },
[1757438797.362] [45354:45356] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1757438797.362] [45354:45356] [CTL] Received Attestation Information from the device
[1757438797.362] [45354:45356] [CTL] Successfully finished commissioning step 'SendAttestationRequest'
[1757438797.362] [45354:45356] [CTL] AutoCommissioner setting attestationElements buffer size 585/585
[1757438797.362] [45354:45356] [CTL] Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1757438797.362] [45354:45356] [CTL] Performing next commissioning step 'AttestationVerification'
[1757438797.362] [45354:45356] [CTL] Verifying Device Attestation information received from the device
[1757438797.362] [45354:45356] [-] Device candidate DAC chain details:
[1757438797.362] [45354:45356] [-] --> DAC's VID: 0xFFF1, PID: 0x8005
[1757438797.362] [45354:45356] [-] ==== DAC certificate considered (492 bytes) ====
[1757438797.362] [45354:45356] [-] -----BEGIN CERTIFICATE-----
[1757438797.362] [45354:45356] [-] MIIB6DCCAY6gAwIBAgIIb9y27QbzWPkwCgYIKoZIzj0EAwIwPTElMCMGA1UEAwwc
[1757438797.362] [45354:45356] [-] TWF0dGVyIERldiBQQUkgMHhGRkYxIG5vIFBJRDEUMBIGCisGAQQBgqJ8AgEMBEZG
[1757438797.362] [45354:45356] [-] RjEwIBcNMjIwMjA1MDAwMDAwWhgPOTk5OTEyMzEyMzU5NTlaMFMxJTAjBgNVBAMM
[1757438797.362] [45354:45356] [-] HE1hdHRlciBEZXYgREFDIDB4RkZGMS8weDgwMDUxFDASBgorBgEEAYKifAIBDARG
[1757438797.362] [45354:45356] [-] RkYxMRQwEgYKKwYBBAGConwCAgwEODAwNTBZMBMGByqGSM49AgEGCCqGSM49AwEH
[1757438797.362] [45354:45356] [-] A0IABH7y8QgrKlZKBUTAphPSGxV1AFUtA18jAiUvzugdbsZ0FzQYqUqI23N0FVjJ
[1757438797.362] [45354:45356] [-] /IrJNJ72fj411fyG6GIgQrAoMzijYDBeMAwGA1UdEwEB/wQCMAAwDgYDVR0PAQH/
[1757438797.362] [45354:45356] [-] BAQDAgeAMB0GA1UdDgQWBBQFMQDwmXEmh8+te1VBSp8+rUy4BzAfBgNVHSMEGDAW
[1757438797.362] [45354:45356] [-] gBRjVA5H9kscONE4hKRi0WwZXY/7PDAKBggqhkjOPQQDAgNIADBFAiEAgZYKAZrC
[1757438797.362] [45354:45356] [-] IRa+ft0amx+sMnaGHJm9Q/vVDNUHKcLuGhcCIBm8NwwKLlrk89/PWHEwpXYWujIJ
[1757438797.362] [45354:45356] [-] /ziDU+xEpwaHrOJB
[1757438797.362] [45354:45356] [-] -----END CERTIFICATE-----
[1757438797.362] [45354:45356] [-] --> DAC certificate SKID: 05:31:00:F0:99:71:26:87:CF:AD:7B:55:41:4A:9F:3E:AD:4C:B8:07
[1757438797.362] [45354:45356] [-] --> DAC certificate AKID: 63:54:0E:47:F6:4B:1C:38:D1:38:84:A4:62:D1:6C:19:5D:8F:FB:3C
[1757438797.362] [45354:45356] [-] ==== PAI certificate considered (463 bytes) ====
[1757438797.362] [45354:45356] [-] -----BEGIN CERTIFICATE-----
[1757438797.362] [45354:45356] [-] MIIByzCCAXGgAwIBAgIIVq2CIq2UW2QwCgYIKoZIzj0EAwIwMDEYMBYGA1UEAwwP
[1757438797.362] [45354:45356] [-] TWF0dGVyIFRlc3QgUEFBMRQwEgYKKwYBBAGConwCAQwERkZGMTAgFw0yMjAyMDUw
[1757438797.362] [45354:45356] [-] MDAwMDBaGA85OTk5MTIzMTIzNTk1OVowPTElMCMGA1UEAwwcTWF0dGVyIERldiBQ
[1757438797.362] [45354:45356] [-] QUkgMHhGRkYxIG5vIFBJRDEUMBIGCisGAQQBgqJ8AgEMBEZGRjEwWTATBgcqhkjO
[1757438797.362] [45354:45356] [-] PQIBBggqhkjOPQMBBwNCAARBmpMVwhc+DIyHbQPM/JRIUmR/f+xeUIL0BZko7KiU
[1757438797.362] [45354:45356] [-] xZQVEwmsYx5MsDOSr2hLC6+35ls7gWLC9Sv5MbjneqqCo2YwZDASBgNVHRMBAf8E
[1757438797.362] [45354:45356] [-] CDAGAQH/AgEAMA4GA1UdDwEB/wQEAwIBBjAdBgNVHQ4EFgQUY1QOR/ZLHDjROISk
[1757438797.362] [45354:45356] [-] YtFsGV2P+zwwHwYDVR0jBBgwFoAUav0idx9RH+y/FkGXZxDc3DGhcX4wCgYIKoZI
[1757438797.362] [45354:45356] [-] zj0EAwIDSAAwRQIhALLvJ/Sa6bUPuR7qyUxNC9u415KcbLiPrOUpNo0SBUwMAiBl
[1757438797.362] [45354:45356] [-] Xckrhr2QmIKmxiF3uCXX0F7b58Ivn+pxIg5+pwP4kQ==
[1757438797.362] [45354:45356] [-] -----END CERTIFICATE-----
[1757438797.362] [45354:45356] [-] --> PAI certificate SKID: 63:54:0E:47:F6:4B:1C:38:D1:38:84:A4:62:D1:6C:19:5D:8F:FB:3C
[1757438797.362] [45354:45356] [-] --> PAI certificate AKID: 6A:FD:22:77:1F:51:1F:EC:BF:16:41:97:67:10:DC:DC:31:A1:71:7E
[1757438797.367] [45354:45356] [CR] mbedTLS error: ECP - The signature is not valid
[1757438797.367] [45354:45356] [CTL] Error on commissioning step 'AttestationVerification': 'src/controller/CHIPDeviceController.cpp:1291: CHIP Error 0x00000020: Failed Device Attestation'
[1757438797.367] [45354:45356] [CTL] Failed verifying attestation information. Now checking DAC chain revoked status.
[1757438797.367] [45354:45356] [CTL] Commissioning stage next step: 'AttestationVerification' -> 'AttestationRevocationCheck'
[1757438797.367] [45354:45356] [CTL] Performing next commissioning step 'AttestationRevocationCheck' with completion status = 'src/controller/CHIPDeviceController.cpp:1291: CHIP Error 0x00000020: Failed Device Attestation'
[1757438797.367] [45354:45356] [CTL] Verifying the device's DAC chain revocation status
[1757438797.367] [45354:45356] [-] WARNING: No revocation delegate available. Revocation checks will be skipped!
[1757438797.367] [45354:45356] [CTL] Failed in verifying 'Attestation Information' command received from the device: err 500 (Attestation signature failed to validate against DAC subject public key)
[1757438797.367] [45354:45356] [CTL] Error on commissioning step 'AttestationRevocationCheck': 'src/controller/CHIPDeviceController.cpp:1338: CHIP Error 0x00000020: Failed Device Attestation'
[1757438797.367] [45354:45356] [CTL] Going from commissioning step 'AttestationRevocationCheck' with lastErr = 'src/controller/CHIPDeviceController.cpp:1338: CHIP Error 0x00000020: Failed Device Attestation' -> 'Cleanup'
[1757438797.367] [45354:45356] [CTL] Performing next commissioning step 'Cleanup' with completion status = 'src/controller/CHIPDeviceController.cpp:1338: CHIP Error 0x00000020: Failed Device Attestation'
[1757438797.367] [45354:45356] [CTL] Disarming failsafe on device 0x79bfa800c110
[1757438797.367] [45354:45356] [DMG] ICR moving to [AddingComm]
[1757438797.367] [45354:45356] [DMG] ICR moving to [AddedComma]
[1757438797.367] [45354:45356] [EM] <<< [E:54433i S:37260 M:199337717] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
[1757438797.368] [45354:45356] [DMG] ICR moving to [AwaitingRe]
[1757438797.368] [45354:45356] [DMG] ICR moving to [AwaitingDe]
[1757438797.449] [45354:45356] [DL] HandlePlatformSpecificBLEEvent 16389
[1757438797.583] [45354:45355] [DL] BLE connection closed: conn=0x79bfb006ccf0
[1757438797.584] [45354:45356] [IN] Clearing BLE pending packets.
[1757438829.400] [45354:45356] [DMG] Time out! failed to receive invoke command response from Exchange: 54433i
[1757438829.400] [45354:45356] [CTL] Ignoring failure to disarm failsafe: src/app/CommandSender.cpp:354: CHIP Error 0x00000032: Timeout
[1757438829.400] [45354:45356] [CTL] Successfully finished commissioning step 'Cleanup'
[1757438829.400] [45354:45356] [DIS] Closing all BLE connections
[1757438829.400] [45354:45356] [IN] SecureSession[0x79bfa800b4b0]: MarkForEviction Type:1 LSID:37260
[1757438829.400] [45354:45356] [SC] SecureSession[0x79bfa800b4b0, LSID:37260]: State change 'kActive' --> 'kPendingEviction'
[1757438829.400] [45354:45356] [IN] SecureSession[0x79bfa800b4b0]: Released - Type:1 LSID:37260
[1757438829.400] [45354:45356] [CTL] Commissioning complete for node ID 0x0000000000000001: src/controller/CHIPDeviceController.cpp:1338: CHIP Error 0x00000020: Failed Device Attestation
[1757438829.400] [45354:45356] [TOO] Device commissioning Failure: src/controller/CHIPDeviceController.cpp:1338: CHIP Error 0x00000020: Failed Device Attestation
[1757438829.400] [45354:45356] [DMG] ICR moving to [AwaitingDe]
[1757438829.400] [45354:45354] [CTL] Shutting down the commissioner
[1757438829.400] [45354:45354] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1757438829.400] [45354:45354] [CTL] Shutting down the controller
[1757438829.400] [45354:45354] [IN] Expiring all sessions for fabric 0x1!!
[1757438829.400] [45354:45354] [FP] Forgetting fabric 0x1
[1757438829.400] [45354:45354] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1757438829.400] [45354:45354] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1757438829.400] [45354:45354] [TS] Reverted Last Known Good Time to previous value
[1757438829.400] [45354:45354] [CTL] Shutting down the commissioner
[1757438829.400] [45354:45354] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1757438829.400] [45354:45354] [CTL] Shutting down the controller
[1757438829.400] [45354:45354] [CTL] Shutting down the System State, this will teardown the CHIP Stack
[1757438829.400] [45354:45354] [DMG] All ReadHandler-s are clean, clear GlobalDirtySet
[1757438829.400] [45354:45354] [FP] Shutting down FabricTable
[1757438829.400] [45354:45354] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1757438829.400] [45354:45354] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1757438829.400] [45354:45354] [TS] Reverted Last Known Good Time to previous value
[1757438829.415] [45354:45354] [DL] Wrote settings to /tmp/chip_counters.ini
[1757438829.415] [45354:45354] [DL] NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1757438829.415] [45354:45354] [DL] Inet Layer shutdown
[1757438829.415] [45354:45354] [DL] BLE Layer shutdown
[1757438829.416] [45354:45354] [DL] WiFi-PAF Layer shutdown
[1757438829.416] [45354:45354] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1757438829.416] [45354:45354] [DL] System Layer shutdown
[1757438829.416] [45354:45354] [TOO] Run command failure: src/controller/CHIPDeviceController.cpp:1338: CHIP Error 0x00000020: Failed Device Attestation
linux1@linux1-Vishal:~/Downloads$ ./chip-tool_x64 pairing code 1 34970112332
[1757438896.962] [45381:45381] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1757438896.962] [45381:45381] [DL] ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs, IGNORING.
[1757438896.962] [45381:45381] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1757438896.962] [45381:45381] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1757438896.962] [45381:45381] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1757438896.977] [45381:45381] [DL] Wrote settings to /tmp/chip_counters.ini
[1757438896.977] [45381:45381] [DL] NVS set: chip-counters/reboot-count = 19 (0x13)
[1757438896.977] [45381:45381] [DL] Failed to get Ethernet interface
[1757438896.977] [45381:45381] [DL] Failed to reset Ethernet statistic counts
[1757438896.977] [45381:45381] [DL] Got WiFi interface: wlp0s20f3
[1757438896.977] [45381:45381] [DL] Found the primary WiFi interface:wlp0s20f3
[1757438896.977] [45381:45381] [PAF] WiFiPAF: WiFiPAFLayer::Init()
[1757438896.977] [45381:45381] [IN] UDP::Init bind&listen port=0
[1757438896.978] [45381:45381] [IN] UDP::Init bound to port=51476
[1757438896.978] [45381:45381] [IN] UDP::Init bind&listen port=0
[1757438896.978] [45381:45381] [IN] UDP::Init bound to port=59294
[1757438896.978] [45381:45381] [IN] BLEBase::Init - setting/overriding transport
[1757438896.978] [45381:45381] [IN] WiFiPAFBase::Init - setting/overriding transport
[1757438896.978] [45381:45381] [IN] TransportMgr initialized
[1757438896.978] [45381:45381] [FP] Initializing FabricTable from persistent storage
[1757438896.978] [45381:45381] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1757438896.978] [45381:45381] [FP] Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xD424E20FF510BCCC, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1757438896.978] [45381:45381] [DMG] Ember attribute persistence requires setting up
[1757438896.978] [45381:45381] [ZCL] Using ZAP configuration...
[1757438896.980] [45381:45381] [DL] Avahi client registered
[1757438896.980] [45381:45381] [CTL] System State Initialized...
[1757438896.980] [45381:45381] [CTL] Setting attestation nonce to random value
[1757438896.980] [45381:45381] [CTL] Setting CSR nonce to random value
[1757438896.980] [45381:45383] [DL] CHIP task running
[1757438896.980] [45381:45383] [DL] HandlePlatformSpecificBLEEvent 32786
[1757438896.981] [45381:45383] [CTL] Setting attestation nonce to random value
[1757438896.981] [45381:45383] [CTL] Setting CSR nonce to random value
[1757438896.983] [45381:45383] [CTL] Generating NOC
[1757438896.985] [45381:45383] [FP] Validating NOC chain
[1757438896.991] [45381:45383] [FP] NOC chain validation successful
[1757438896.991] [45381:45383] [FP] Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1757438896.991] [45381:45383] [TS] Last Known Good Time: 2023-10-14T01:16:48
[1757438896.991] [45381:45383] [TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
[1757438896.991] [45381:45383] [TS] Retaining current Last Known Good Time
[1757438896.991] [45381:45383] [FP] Metadata for Fabric 0x1 persisted to storage.
[1757438896.991] [45381:45383] [TS] Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1757438896.992] [45381:45383] [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: D424E20FF510BCCC)
[1757438896.993] [45381:45383] [CTL] Setting attestation nonce to random value
[1757438896.993] [45381:45383] [CTL] Setting CSR nonce to random value
[1757438896.993] [45381:45383] [CTL] Stopping commissionable node discovery over DNS-SD
[1757438896.993] [45381:45383] [CTL] Starting commissionable node discovery over DNS-SD
[1757438897.003] [45381:45383] [DL] Avahi browse: cache exhausted
[1757438898.005] [45381:45383] [DL] Avahi browse: all for now
[1757438927.021] [45381:45383] [CTL] Discovery timed out
[1757438927.022] [45381:45383] [CTL] Stopping commissionable node discovery over DNS-SD
[1757438927.022] [45381:45383] [TOO] Secure Pairing Failed
[1757438927.022] [45381:45381] [CTL] Shutting down the commissioner
[1757438927.022] [45381:45381] [CTL] Stopping commissionable node discovery over DNS-SD
[1757438927.022] [45381:45381] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1757438927.022] [45381:45381] [CTL] Shutting down the controller
[1757438927.022] [45381:45381] [IN] Expiring all sessions for fabric 0x1!!
[1757438927.022] [45381:45381] [FP] Forgetting fabric 0x1
[1757438927.022] [45381:45381] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1757438927.022] [45381:45381] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1757438927.022] [45381:45381] [TS] Reverted Last Known Good Time to previous value
[1757438927.022] [45381:45381] [CTL] Shutting down the commissioner
[1757438927.022] [45381:45381] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1757438927.022] [45381:45381] [CTL] Shutting down the controller
[1757438927.022] [45381:45381] [CTL] Shutting down the System State, this will teardown the CHIP Stack
[1757438927.022] [45381:45381] [DMG] All ReadHandler-s are clean, clear GlobalDirtySet
[1757438927.022] [45381:45381] [FP] Shutting down FabricTable
[1757438927.022] [45381:45381] [TS] Pending Last Known Good Time: 2023-10-14T01:16:48
[1757438927.022] [45381:45381] [TS] Previous Last Known Good Time: 2023-10-14T01:16:48
[1757438927.022] [45381:45381] [TS] Reverted Last Known Good Time to previous value
[1757438927.037] [45381:45381] [DL] Wrote settings to /tmp/chip_counters.ini
[1757438927.037] [45381:45381] [DL] NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1757438927.037] [45381:45381] [DL] Inet Layer shutdown
[1757438927.037] [45381:45381] [DL] BLE Layer shutdown
[1757438927.037] [45381:45381] [DL] WiFi-PAF Layer shutdown
[1757438927.037] [45381:45381] [PAF] WiFiPAF: Closing all WiFiPAF sessions to shutdown
[1757438927.037] [45381:45381] [DL] System Layer shutdown
[1757438927.037] [45381:45381] [TOO] Run command failure: examples/chip-tool/commands/pairing/PairingCommand.cpp:404: CHIP Error 0x00000003: Incorrect state
linux1@linux1-Vishal:~/Downloads$
log from firmware side
*** Booting My Application v3.1.0-6c6e5b32496e *** *** Using nRF Connect SDK v3.1.0-6c6e5b32496e *** *** Using Zephyr OS v4.1.99-1612683d4010 *** D: 49 [DL]Boot reason: 1 I: 53 [DL]BLE address: DA:EB:1A:99:75:64 I: 69 [DL]CHIP task running I: Init CHIP stack I: 74 [DL]OpenThread started: OK I: 77 [DL]Setting OpenThread device type to ROUTER D: Registered new test event: 0xffffffff00000000 D: Registered new test event: 0xffffffff10000000 I: 91 [SVR]Initializing subscription resumption storage... I: 96 [SVR]Server initializing... I: 99 [TS]Last Known Good Time: 2023-10-14T01:16:48 I: 104 [DMG]AccessControl: initializing I: 108 [DMG]Examples::AccessControlDelegate::Init I: 112 [DMG]AccessControl: setting I: 116 [DMG]DefaultAclStorage: initializing I: 120 [DMG]DefaultAclStorage: 0 entries loaded D: 124 [IN]UDP::Init bind&listen port=5540 D: 128 [IN]UDP::Init bound to port=5540 D: 131 [IN]BLEBase::Init - setting/overriding transport D: 136 [IN]TransportMgr initialized D: 140 [DL]Using Thread extended MAC for hostname. I: 146 [ZCL]Using ZAP configuration... I: 151 [DMG]AccessControlCluster: initializing I: 156 [ZCL]Endpoint 1 On/off already set to new value D: 162 [IN]SecureSession[0x200102d8]: Allocated Type:1 LSID:6165 D: 168 [DL]CHIPoBLE advertising set to on I: 172 [DIS]Updating services using commissioning mode 1 E: 177 [DIS]Failed to remove advertised services: 3 D: 181 [DL]Using Thread extended MAC for hostname. I: 186 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 cp=0 E: 195 [DIS]Failed to advertise commissionable node: 3 E: 200 [DIS]Failed to finalize service update: 3 I: 204 [DIS]Updating services using commissioning mode 1 E: 209 [DIS]Failed to remove advertised services: 3 D: 214 [DL]Using Thread extended MAC for hostname. I: 219 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 cp=0 E: 228 [DIS]Failed to advertise commissionable node: 3 E: 233 [DIS]Failed to finalize service update: 3 I: 237 [IN]CASE Server enabling CASE session setups D: 242 [IN]SecureSession[0x200103b0]: Allocated Type:2 LSID:6166 I: 248 [SVR]Server Listening... I: 251 [DL]Device Configuration: I: 254 [DL] Serial Number: 11223344556677889900 I: 258 [DL] Vendor Id: 65521 (0xFFF1) I: 262 [DL] Product Id: 32773 (0x8005) I: 265 [DL] Product Name: not-specified I: 269 [DL] Hardware Version: 0 I: 272 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 277 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) I: 284 [DL] Manufacturing Date: 2022-01-01 I: 288 [DL] Device Type: 65535 (0xFFFF) I: 291 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00] I: 296 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 302 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00 I: 311 [SVR]Manual pairing code: [34970112332] E: 315 [DL]Long dispatch time: 244 ms, for event type 2 I: 324 [DL]CHIPoBLE advertising started I: 328 [DL]NFC Tag emulation started I: 30328 [DL]CHIPoBLE advertising mode changed to slow I: 30337 [DL]CHIPoBLE advertising started I: 37027 [DL]Current number of connections: 1/1 I: 37032 [DL]BLE connection established (ConnId: 0x00) I: 37037 [DL]CHIPoBLE advertising stopped I: 37041 [DL]NFC Tag emulation stopped D: 38440 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 38447 [BLE]local and remote recv window sizes = 5 I: 38452 [BLE]selected BTP version 4 I: 38455 [BLE]using BTP fragment sizes rx 244 / tx 244. D: 38575 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 38579 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 38587 [IN]BLE EndPoint 0x2000fc10 Connection Complete I: 38592 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247) D: 38665 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38673 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 38680 [EM]>>> [E:2042r S:0 M:90621816] (U) Msg RX from 0:85C71AD7BA912F51 [0000] to 0000000000000000 --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98) I: 38696 [EM]<<< [E:2042r S:0 M:57345420] (U) Msg TX from 0000000000000000 to 0:85C71AD7BA912F51 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154) D: 38711 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 159) I: 38719 [SVR]Commissioning session establishment step started D: 38800 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 38808 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 38815 [EM]>>> [E:2042r S:0 M:90621817] (U) Msg RX from 0:85C71AD7BA912F51 [0000] to 0000000000000000 --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92) I: 38950 [EM]<<< [E:2042r S:0 M:57345421] (U) Msg TX from 0000000000000000 to 0:85C71AD7BA912F51 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127) D: 38964 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132) E: 38972 [DL]Long dispatch time: 164 ms, for event type 16388 D: 39025 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39033 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 39040 [EM]>>> [E:2042r S:0 M:90621818] (U) Msg RX from 0:85C71AD7BA912F51 [0000] to 0000000000000000 --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59) I: 39055 [EM]<<< [E:2042r S:0 M:57345422] (U) Msg TX from 0000000000000000 to 0:85C71AD7BA912F51 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) (B:30) D: 39069 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 39079 [SC]SecureSession[0x200102d8, LSID:6165]: State change 'kEstablishing' --> 'kActive' D: 39087 [IN]SecureSession[0x200102d8]: Activated - Type:1 LSID:6165 D: 39093 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:6165 PSID:60317! I: 39102 [SVR]Commissioning completed session establishment step I: 39108 [DIS]Updating services using commissioning mode 0 E: 39113 [DIS]Failed to remove advertised services: 3 E: 39118 [DIS]Failed to finalize service update: 3 D: 39122 [DL]CHIPoBLE advertising set to off I: 39126 [SVR]Device completed Rendezvous process D: 39160 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39168 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 39176 [EM]>>> [E:2043r S:6165 M:120012066] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:134) D: 39190 [IM]Received Read request I: 39210 [EM]<<< [E:2043r S:6165 M:193618879] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:257) D: 39224 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 39295 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39302 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 20) D: 39385 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39393 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 39401 [EM]>>> [E:2044r S:6165 M:120012067] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:103) D: 39414 [IM]Received Read request E: 39421 [DMG]Read request on unknown cluster - no data version available E: 39427 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0002err = 5c3 E: 39439 [DMG]Read request on unknown cluster - no data version available E: 39446 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0001err = 5c3 E: 39458 [DMG]Read request on unknown cluster - no data version available E: 39464 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0000err = 5c3 E: 39476 [DMG]Read request on unknown cluster - no data version available E: 39483 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0007err = 5c3 E: 39495 [DMG]Read request on unknown cluster - no data version available E: 39502 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0006err = 5c3 I: 39516 [EM]<<< [E:2044r S:6165 M:193618880] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:181) D: 39529 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 186) D: 39655 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39700 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 39709 [EM]>>> [E:2045r S:6165 M:120012068] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65) I: 39724 [FS]GeneralCommissioning: Received ArmFailSafe (60s) I: 39730 [EM]<<< [E:2045r S:6165 M:193618881] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) D: 39745 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 39835 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39843 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 39851 [EM]>>> [E:2046r S:6165 M:120012069] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:70) I: 39869 [EM]<<< [E:2046r S:6165 M:193618882] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) D: 39883 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 39970 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 39978 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 39986 [EM]>>> [E:2047r S:6165 M:120012070] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62) I: 40001 [ZCL]OpCreds: Certificate Chain request received for PAI I: 40010 [EM]<<< [E:2047r S:6165 M:193618883] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:527) D: 40025 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 40105 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40113 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 40195 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40203 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48) D: 40285 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40293 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 40301 [EM]>>> [E:2048r S:6165 M:120012071] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62) I: 40316 [ZCL]OpCreds: Certificate Chain request received for DAC I: 40325 [EM]<<< [E:2048r S:6165 M:193618884] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:556) D: 40340 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 40420 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40428 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 40510 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40518 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77) D: 40600 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40608 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 40616 [EM]>>> [E:2049r S:6165 M:120012072] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94) I: 40631 [ZCL]OpCreds: Received an AttestationRequest command I: 40666 [ZCL]OpCreds: AttestationRequest successful. I: 40676 [EM]<<< [E:2049r S:6165 M:193618885] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:716) D: 40690 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 40780 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40788 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 40870 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40878 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 237) D: 40960 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 40968 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 40976 [EM]>>> [E:2050r S:6165 M:120012073] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65) I: 40991 [FS]GeneralCommissioning: Received ArmFailSafe (0s) I: 40996 [FS]Fail-safe timer expired I: 41001 [EM]<<< [E:2050r S:6165 M:193618886] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) D: 41016 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) E: 41023 [SVR]Failsafe timer expired D: 41027 [IN]SecureSession[0x200102d8]: MarkForEviction Type:1 LSID:6165 I: 41033 [SC]SecureSession[0x200102d8, LSID:6165]: State change 'kActive' --> 'kPendingEviction' D: 41042 [IN]SecureSession[0x200102d8]: Released - Type:1 LSID:6165 E: 41048 [SVR]Commissioning failed (attempt 1): 32 D: 41053 [IN]Clearing BLE pending packets. I: 41056 [BLE]Releasing end point's BLE connection back to application. I: 41063 [DL]Closing BLE GATT connection (ConnId 00) D: 41069 [IN]SecureSession[0x200102d8]: Allocated Type:1 LSID:6167 D: 41075 [DL]CHIPoBLE advertising set to on I: 41078 [DIS]Updating services using commissioning mode 1 E: 41084 [DIS]Failed to remove advertised services: 3 D: 41089 [DL]Using Thread extended MAC for hostname. I: 41093 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 cp=0 E: 41104 [DIS]Failed to advertise commissionable node: 3 E: 41109 [DIS]Failed to finalize service update: 3 E: 41113 [ZCL]OpCreds: Got FailSafeTimerExpired E: 41118 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry! I: 41124 [TS]Pending Last Known Good Time: 2023-10-14T01:16:48 I: 41130 [TS]Previous Last Known Good Time: 2023-10-14T01:16:48 I: 41136 [TS]Reverted Last Known Good Time to previous value E: 41141 [DL]Long dispatch time: 118 ms, for event type 32784 I: 41147 [FS]Fail-safe cleanly disarmed D: 41151 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x0e) I: 41158 [DL]Current number of connections: 0/1 I: 41163 [DL]BLE GAP connection terminated (reason 0x16) I: 41171 [DL]CHIPoBLE advertising started I: 41175 [DL]NFC Tag emulation started I: 71175 [DL]CHIPoBLE advertising mode changed to slow I: 71185 [DL]CHIPoBLE advertising started I: 154903 [DL]Current number of connections: 1/1 I: 154908 [DL]BLE connection established (ConnId: 0x00) I: 154913 [DL]CHIPoBLE advertising stopped I: 154917 [DL]NFC Tag emulation stopped D: 156300 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 156307 [BLE]local and remote recv window sizes = 5 I: 156312 [BLE]selected BTP version 4 I: 156316 [BLE]using BTP fragment sizes rx 244 / tx 244. D: 156435 [DL]ConnId: 0x00, New CCCD value: 0x0002 D: 156440 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6) D: 156447 [IN]BLE EndPoint 0x2000fc10 Connection Complete I: 156452 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247) D: 156525 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 156533 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 156541 [EM]>>> [E:54425r S:0 M:123803580] (U) Msg RX from 0:2A81D60EC0236D4B [0000] to 0000000000000000 --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98) I: 156556 [EM]<<< [E:54425r S:0 M:57345423] (U) Msg TX from 0000000000000000 to 0:2A81D60EC0236D4B [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154) D: 156571 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 159) I: 156579 [SVR]Commissioning session establishment step started D: 156705 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 156713 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 156721 [EM]>>> [E:54425r S:0 M:123803581] (U) Msg RX from 0:2A81D60EC0236D4B [0000] to 0000000000000000 --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92) I: 156855 [EM]<<< [E:54425r S:0 M:57345424] (U) Msg TX from 0000000000000000 to 0:2A81D60EC0236D4B [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127) D: 156870 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132) E: 156877 [DL]Long dispatch time: 164 ms, for event type 16388 D: 156930 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 156938 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 156946 [EM]>>> [E:54425r S:0 M:123803582] (U) Msg RX from 0:2A81D60EC0236D4B [0000] to 0000000000000000 --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59) I: 156960 [EM]<<< [E:54425r S:0 M:57345425] (U) Msg TX from 0000000000000000 to 0:2A81D60EC0236D4B [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) (B:30) D: 156975 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35) I: 156984 [SC]SecureSession[0x200102d8, LSID:6167]: State change 'kEstablishing' --> 'kActive' D: 156993 [IN]SecureSession[0x200102d8]: Activated - Type:1 LSID:6167 D: 156999 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:6167 PSID:37260! I: 157008 [SVR]Commissioning completed session establishment step I: 157014 [DIS]Updating services using commissioning mode 0 E: 157019 [DIS]Failed to remove advertised services: 3 E: 157024 [DIS]Failed to finalize service update: 3 D: 157029 [DL]CHIPoBLE advertising set to off I: 157033 [SVR]Device completed Rendezvous process D: 157065 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 157073 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 157082 [EM]>>> [E:54426r S:6167 M:199337710] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:134) D: 157095 [IM]Received Read request I: 157115 [EM]<<< [E:54426r S:6167 M:192540095] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:257) D: 157128 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 157200 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 157208 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 20) D: 157290 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 157298 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 157307 [EM]>>> [E:54427r S:6167 M:199337711] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:103) D: 157320 [IM]Received Read request E: 157326 [DMG]Read request on unknown cluster - no data version available E: 157333 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0002err = 5c3 E: 157345 [DMG]Read request on unknown cluster - no data version available E: 157352 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0001err = 5c3 E: 157364 [DMG]Read request on unknown cluster - no data version available E: 157370 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0000err = 5c3 E: 157382 [DMG]Read request on unknown cluster - no data version available E: 157389 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0007err = 5c3 E: 157401 [DMG]Read request on unknown cluster - no data version available E: 157408 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0006err = 5c3 I: 157422 [EM]<<< [E:54427r S:6167 M:192540096] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:181) D: 157436 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 186) D: 157560 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 157606 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 157614 [EM]>>> [E:54428r S:6167 M:199337712] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65) I: 157629 [FS]GeneralCommissioning: Received ArmFailSafe (60s) I: 157636 [EM]<<< [E:54428r S:6167 M:192540097] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) D: 157651 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 157740 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 157748 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 157756 [EM]>>> [E:54429r S:6167 M:199337713] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:70) I: 157773 [EM]<<< [E:54429r S:6167 M:192540098] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) D: 157788 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) D: 157875 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 157883 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 157891 [EM]>>> [E:54430r S:6167 M:199337714] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62) I: 157906 [ZCL]OpCreds: Certificate Chain request received for PAI I: 157916 [EM]<<< [E:54430r S:6167 M:192540099] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:527) D: 157931 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 158010 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158018 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 158100 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158108 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48) D: 158190 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158198 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 158206 [EM]>>> [E:54431r S:6167 M:199337715] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62) I: 158221 [ZCL]OpCreds: Certificate Chain request received for DAC I: 158231 [EM]<<< [E:54431r S:6167 M:192540100] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:556) D: 158246 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 158325 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158333 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 158415 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158423 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77) D: 158505 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158513 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 158522 [EM]>>> [E:54432r S:6167 M:199337716] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94) I: 158537 [ZCL]OpCreds: Received an AttestationRequest command I: 158571 [ZCL]OpCreds: AttestationRequest successful. I: 158580 [EM]<<< [E:54432r S:6167 M:192540101] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:716) D: 158595 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 158685 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158693 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244) D: 158775 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158783 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 237) D: 158865 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00) D: 158873 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00) I: 158881 [EM]>>> [E:54433r S:6167 M:199337717] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65) I: 158897 [FS]GeneralCommissioning: Received ArmFailSafe (0s) I: 158902 [FS]Fail-safe timer expired I: 158907 [EM]<<< [E:54433r S:6167 M:192540102] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66) D: 158921 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71) E: 158929 [SVR]Failsafe timer expired D: 158933 [IN]SecureSession[0x200102d8]: MarkForEviction Type:1 LSID:6167 I: 158939 [SC]SecureSession[0x200102d8, LSID:6167]: State change 'kActive' --> 'kPendingEviction' D: 158948 [IN]SecureSession[0x200102d8]: Released - Type:1 LSID:6167 E: 158954 [SVR]Commissioning failed (attempt 2): 32 D: 158959 [IN]Clearing BLE pending packets. I: 158963 [BLE]Releasing end point's BLE connection back to application. I: 158969 [DL]Closing BLE GATT connection (ConnId 00) D: 158975 [IN]SecureSession[0x200102d8]: Allocated Type:1 LSID:6168 D: 158981 [DL]CHIPoBLE advertising set to on I: 158985 [DIS]Updating services using commissioning mode 1 E: 158990 [DIS]Failed to remove advertised services: 3 D: 158995 [DL]Using Thread extended MAC for hostname. I: 159000 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 cp=0 E: 159010 [DIS]Failed to advertise commissionable node: 3 E: 159015 [DIS]Failed to finalize service update: 3 E: 159020 [ZCL]OpCreds: Got FailSafeTimerExpired E: 159024 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry! I: 159031 [TS]Pending Last Known Good Time: 2023-10-14T01:16:48 I: 159037 [TS]Previous Last Known Good Time: 2023-10-14T01:16:48 I: 159042 [TS]Reverted Last Known Good Time to previous value E: 159049 [DL]Long dispatch time: 120 ms, for event type 32784 I: 159054 [FS]Fail-safe cleanly disarmed D: 159058 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x0e) I: 159066 [DL]Current number of connections: 0/1 I: 159070 [DL]BLE GAP connection terminated (reason 0x16) I: 159079 [DL]CHIPoBLE advertising started I: 159083 [DL]NFC Tag emulation started I: 189082 [DL]CHIPoBLE advertising mode changed to slow I: 189091 [DL]CHIPoBLE advertising started *** Booting My Application v3.1.0-6c6e5b32496e *** *** Using nRF Connect SDK v3.1.0-6c6e5b32496e *** *** Using Zephyr OS v4.1.99-1612683d4010 *** D: 50 [DL]Boot reason: 1 I: 54 [DL]BLE address: DA:55:08:86:3C:06 I: 69 [DL]CHIP task running I: Init CHIP stack I: 74 [DL]OpenThread started: OK I: 77 [DL]Setting OpenThread device type to ROUTER D: Registered new test event: 0xffffffff00000000 D: Registered new test event: 0xffffffff10000000 I: 91 [SVR]Initializing subscription resumption storage... I: 97 [SVR]Server initializing... I: 100 [TS]Last Known Good Time: 2023-10-14T01:16:48 I: 105 [DMG]AccessControl: initializing I: 109 [DMG]Examples::AccessControlDelegate::Init I: 113 [DMG]AccessControl: setting I: 117 [DMG]DefaultAclStorage: initializing I: 120 [DMG]DefaultAclStorage: 0 entries loaded D: 125 [IN]UDP::Init bind&listen port=5540 D: 129 [IN]UDP::Init bound to port=5540 D: 132 [IN]BLEBase::Init - setting/overriding transport D: 137 [IN]TransportMgr initialized D: 142 [DL]Using Thread extended MAC for hostname. I: 147 [ZCL]Using ZAP configuration... I: 152 [DMG]AccessControlCluster: initializing I: 157 [ZCL]Endpoint 1 On/off already set to new value D: 163 [IN]SecureSession[0x200102d8]: Allocated Type:1 LSID:6290 D: 169 [DL]CHIPoBLE advertising set to on I: 173 [DIS]Updating services using commissioning mode 1 E: 178 [DIS]Failed to remove advertised services: 3 D: 183 [DL]Using Thread extended MAC for hostname. I: 187 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 cp=0 E: 196 [DIS]Failed to advertise commissionable node: 3 E: 201 [DIS]Failed to finalize service update: 3 I: 206 [DIS]Updating services using commissioning mode 1 E: 211 [DIS]Failed to remove advertised services: 3 D: 215 [DL]Using Thread extended MAC for hostname. I: 220 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1 cp=0 E: 229 [DIS]Failed to advertise commissionable node: 3 E: 234 [DIS]Failed to finalize service update: 3 I: 239 [IN]CASE Server enabling CASE session setups D: 243 [IN]SecureSession[0x200103b0]: Allocated Type:2 LSID:6291 I: 249 [SVR]Server Listening... I: 252 [DL]Device Configuration: I: 255 [DL] Serial Number: 11223344556677889900 I: 260 [DL] Vendor Id: 65521 (0xFFF1) I: 263 [DL] Product Id: 32773 (0x8005) I: 267 [DL] Product Name: not-specified I: 270 [DL] Hardware Version: 0 I: 273 [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 I: 279 [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) I: 285 [DL] Manufacturing Date: 2022-01-01 I: 289 [DL] Device Type: 65535 (0xFFFF) I: 293 [SVR]SetupQRCode: [MT:6FCJ142C00KA0648G00] I: 297 [SVR]Copy/paste the below URL in a browser to see the QR Code: I: 303 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00 I: 312 [SVR]Manual pairing code: [34970112332] E: 317 [DL]Long dispatch time: 245 ms, for event type 2 I: 325 [DL]CHIPoBLE advertising started I: 329 [DL]NFC Tag emulation started I: 30329 [DL]CHIPoBLE advertising mode changed to slow I: 30338 [DL]CHIPoBLE advertising started
Best regards,
Vishal Gade.
