Chip tool debugging device error

[DoubleAmaing]

Hi，

I have a problem, please help me, I can't see where is the problem 。

refer to

Working with the CHIP Tool — Matter documentation (nRF Connect SDK) (nordicsemi.com)

Environment:

Raspberry Pie (Border Router)

router

PC (Win10) - VirtualBox (Ubuntu 22.04)

Board (Light_Blub)

Chih TooL: 

Using pre compiled, version 2.4.1

Releases · nrfconnect/sdk-connectedhomeip (github.com)

The error is as follows:

yd@yd-VirtualBox:~/chip-tool-linux_x64$ ./chip-tool-debug pairing ble-thread 1 hex:0e08000000000001000035060004001fffe00708fd5ea4308ad9f2d40c0402a0f7f8051000112233445566778899aabbccddeeff03104f70656e5468726561644d61747465720410b02285723920d515813e00fa447e4ec7000300000f0208111111112222222201021234 20202021 3840
[1693281548.188769][5543:5543] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1693281548.194245][5543:5543] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1693281548.194434][5543:5543] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1693281548.194632][5543:5543] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1693281548.195042][5543:5543] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-rNwByq)
[1693281548.196393][5543:5543] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1693281548.196433][5543:5543] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
[1693281548.196860][5543:5543] CHIP:DL: Got Ethernet interface: enp0s3
[1693281548.197063][5543:5543] CHIP:DL: Found the primary Ethernet interface:enp0s3
[1693281548.197721][5543:5543] CHIP:DL: Failed to get WiFi interface
[1693281548.197791][5543:5543] CHIP:DL: Failed to reset WiFi statistic counts
[1693281548.198828][5543:5543] CHIP:IN: UDP::Init bind&listen port=0
[1693281548.198960][5543:5543] CHIP:IN: UDP::Init bound to port=34870
[1693281548.198969][5543:5543] CHIP:IN: UDP::Init bind&listen port=0
[1693281548.199010][5543:5543] CHIP:IN: UDP::Init bound to port=47444
[1693281548.199017][5543:5543] CHIP:IN: BLEBase::Init - setting/overriding transport
[1693281548.199020][5543:5543] CHIP:IN: TransportMgr initialized
[1693281548.199040][5543:5543] CHIP:FP: Initializing FabricTable from persistent storage
[1693281548.206252][5543:5543] CHIP:TS: Last Known Good Time: 2023-07-11T07:57:00
[1693281548.212065][5543:5543] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xC3F8DB39D71B1829, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1693281548.216526][5543:5543] CHIP:ZCL: Using ZAP configuration...
[1693281548.220250][5543:5543] CHIP:DL: Avahi client registered
[1693281548.221826][5543:5543] CHIP:CTL: System State Initialized...
[1693281548.223314][5543:5543] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1693281548.223357][5543:5543] CHIP:CTL: Setting attestation nonce to random value
[1693281548.223375][5543:5543] CHIP:CTL: Setting CSR nonce to random value
[1693281548.223642][5543:5545] CHIP:DL: CHIP task running
[1693281548.223761][5543:5545] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1693281548.223893][5543:5545] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1693281548.224037][5543:5545] CHIP:CTL: Setting attestation nonce to random value
[1693281548.224061][5543:5545] CHIP:CTL: Setting CSR nonce to random value
[1693281548.229926][5543:5545] CHIP:CTL: Generating NOC
[1693281548.236726][5543:5545] CHIP:FP: Validating NOC chain
[1693281548.276048][5543:5545] CHIP:FP: NOC chain validation successful
[1693281548.276157][5543:5545] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1693281548.276350][5543:5545] CHIP:TS: Last Known Good Time: 2023-07-11T07:57:00
[1693281548.276435][5543:5545] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1693281548.276440][5543:5545] CHIP:TS: Retaining current Last Known Good Time
[1693281548.279811][5543:5545] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1693281548.283222][5543:5545] CHIP:TS: Committing Last Known Good Time to storage: 2023-07-11T07:57:00
[1693281548.285262][5543:5545] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: C3F8DB39D71B1829)
[1693281548.297085][5543:5545] CHIP:CTL: Setting thread operational dataset from parameters
[1693281548.297371][5543:5545] CHIP:CTL: Setting attestation nonce to random value
[1693281548.297960][5543:5545] CHIP:CTL: Setting CSR nonce to random value
[1693281548.297977][5543:5545] CHIP:CTL: Commission called for node ID 0x0000000000000001
[1693281548.310807][5543:5544] CHIP:DL: TRACE: Bus acquired for name C-15a7
[1693281573.317555][5543:5544] CHIP:DL: FAIL: Error getting object manager client: Error calling StartServiceByName for org.bluez: Timeout was reached
[1693281573.318147][5543:5545] CHIP:DL: PlatformBlueZInit init success
[1693281573.318165][5543:5545] CHIP:DIS: Closing all BLE connections
[1693281573.318194][5543:5545] CHIP:BLE: No adapter available for new connection establishment
[1693281573.318201][5543:5545] CHIP:DL: Long dispatch time: 25021 ms, for event type 2
[1693281668.226041][5543:5543] CHIP:CTL: Shutting down the commissioner
[1693281668.226358][5543:5543] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1693281668.226458][5543:5543] CHIP:CTL: Shutting down the controller
[1693281668.226471][5543:5543] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1693281668.226476][5543:5543] CHIP:FP: Forgetting fabric 0x1
[1693281668.226488][5543:5543] CHIP:TS: Pending Last Known Good Time: 2023-07-11T07:57:00
[1693281668.226557][5543:5543] CHIP:TS: Previous Last Known Good Time: 2023-07-11T07:57:00
[1693281668.226561][5543:5543] CHIP:TS: Reverted Last Known Good Time to previous value
[1693281668.226573][5543:5543] CHIP:CTL: Shutting down the commissioner
[1693281668.226576][5543:5543] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1693281668.226579][5543:5543] CHIP:CTL: Shutting down the controller
[1693281668.226582][5543:5543] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1693281668.227063][5543:5543] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1693281668.227191][5543:5543] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1693281668.227207][5543:5543] CHIP:FP: Shutting down FabricTable
[1693281668.227214][5543:5543] CHIP:TS: Pending Last Known Good Time: 2023-07-11T07:57:00
[1693281668.227252][5543:5543] CHIP:TS: Previous Last Known Good Time: 2023-07-11T07:57:00
[1693281668.227257][5543:5543] CHIP:TS: Reverted Last Known Good Time to previous value
[1693281668.227409][5543:5543] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ed2AOW)
[1693281668.228819][5543:5543] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1693281668.228932][5543:5543] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1693281668.228943][5543:5543] CHIP:DL: Inet Layer shutdown
[1693281668.228947][5543:5543] CHIP:DL: BLE shutdown

(process:5543): GLib-GObject-CRITICAL **: 12:01:08.228: g_object_unref: assertion 'G_IS_OBJECT (object)' failed
[1693281668.229205][5543:5543] CHIP:DL: System Layer shutdown
[1693281668.229612][5543:5543] CHIP:TOO: Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:537: CHIP Error 0x00000032: Timeout

[AHaug]

Hi,

[1693281573.317555][5543:5544] CHIP:DL: FAIL: Error getting object manager client: Error calling StartServiceByName for org.bluez: Timeout was reached
[1693281573.318147][5543:5545] CHIP:DL: PlatformBlueZInit init success
[1693281573.318165][5543:5545] CHIP:DIS: Closing all BLE connections
[1693281573.318194][5543:5545] CHIP:BLE: No adapter available for new connection establishment

It looks like your VM does not have Bluetooth, which is why you can't find any available connection to establish. Are you able to verify if this is the case?

In general, I would recommend you to use a proper supported Linux distribution for Chip Tool as it is a bit tricky to get CHIP-tool to work on virtual machine. You will have to sort the bridging of Bluetooth and Wi-Fi, since the VM has a ethernet connection via the host by default and it does not have Bluetooth by default

Kind regards,
Andreas

[DoubleAmaing]

Hi, thank you.

I cannot solve the Bluetooth issue with VM.

So I used a Linux host (Ubuntu 22.04)

Execute commands： ./ Chip-tool-debug

I can see that the Cluster appears correctly.

However, when I ran the distribution network command, it encountered an error. Could you please help me take a look? Thank you。

yida@yida-ThinkPad-E470:~$ ./chip-tool-debug pairing ble-thread 1 hex:0e080000000000010000000300000d35060004001fffe00208ee7e4a2d48cdfd7e0708fd131483b543b1000510253bf95c157a90fe0984c54686572c74030f4f70656e5468726561642d643666370102d6f70410e2b8eaa64e39fc95ac12cc7b8757bd410c0402a0f7f8 20202021 3840
[1693455991.857097][4839:4839] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1693455991.857259][4839:4839] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1693455991.857292][4839:4839] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1693455991.857312][4839:4839] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1693455991.857419][4839:4839] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-GRdMES)
[1693455991.857580][4839:4839] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1693455991.857592][4839:4839] CHIP:DL: NVS set: chip-counters/reboot-count = 4 (0x4)
[1693455991.857767][4839:4839] CHIP:DL: Got Ethernet interface: enp4s0
[1693455991.857872][4839:4839] CHIP:DL: Found the primary Ethernet interface:enp4s0
[1693455991.857981][4839:4839] CHIP:DL: Got WiFi interface: wlp5s0
[1693455991.858096][4839:4839] CHIP:DL: Found the primary WiFi interface:wlp5s0
[1693455991.858111][4839:4839] CHIP:IN: UDP::Init bind&listen port=0
[1693455991.858167][4839:4839] CHIP:IN: UDP::Init bound to port=35531
[1693455991.858173][4839:4839] CHIP:IN: UDP::Init bind&listen port=0
[1693455991.858190][4839:4839] CHIP:IN: UDP::Init bound to port=60013
[1693455991.858194][4839:4839] CHIP:IN: BLEBase::Init - setting/overriding transport
[1693455991.858198][4839:4839] CHIP:IN: TransportMgr initialized
[1693455991.858210][4839:4839] CHIP:FP: Initializing FabricTable from persistent storage
[1693455991.858251][4839:4839] CHIP:TS: Last Known Good Time: 2023-07-11T07:53:58
[1693455991.858390][4839:4839] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x9E45793F71B1363E, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1693455991.858814][4839:4839] CHIP:ZCL: Using ZAP configuration...
[1693455991.860751][4839:4839] CHIP:DL: Avahi client registered
[1693455991.861340][4839:4839] CHIP:CTL: System State Initialized...
[1693455991.861376][4839:4839] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1693455991.861388][4839:4839] CHIP:CTL: Setting attestation nonce to random value
[1693455991.861395][4839:4839] CHIP:CTL: Setting CSR nonce to random value
[1693455991.861515][4839:4841] CHIP:DL: CHIP task running
[1693455991.861566][4839:4841] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1693455991.861642][4839:4841] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1693455991.861651][4839:4841] CHIP:CTL: Setting attestation nonce to random value
[1693455991.861656][4839:4841] CHIP:CTL: Setting CSR nonce to random value
[1693455991.865085][4839:4841] CHIP:CTL: Generating NOC
[1693455991.868697][4839:4841] CHIP:FP: Validating NOC chain
[1693455991.884270][4839:4841] CHIP:FP: NOC chain validation successful
[1693455991.884290][4839:4841] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1693455991.884297][4839:4841] CHIP:TS: Last Known Good Time: 2023-07-11T07:53:58
[1693455991.884301][4839:4841] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1693455991.884305][4839:4841] CHIP:TS: Retaining current Last Known Good Time
[1693455991.884814][4839:4841] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1693455991.885274][4839:4841] CHIP:TS: Committing Last Known Good Time to storage: 2023-07-11T07:53:58
[1693455991.885681][4839:4841] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 9E45793F71B1363E)
[1693455991.889681][4839:4841] CHIP:CTL: Setting thread operational dataset from parameters
[1693455991.889689][4839:4841] CHIP:CTL: Setting attestation nonce to random value
[1693455991.889695][4839:4841] CHIP:CTL: Setting CSR nonce to random value
[1693455991.889701][4839:4841] CHIP:CTL: Commission called for node ID 0x0000000000000001
[1693455991.891513][4839:4840] CHIP:DL: TRACE: Bus acquired for name C-12e7
[1693455991.895595][4839:4841] CHIP:DL: PlatformBlueZInit init success
[1693455991.897811][4839:4840] CHIP:BLE: BLE removing known devices.
[1693455991.898425][4839:4840] CHIP:BLE: BLE initiating scan.
[1693455992.016874][4839:4841] CHIP:DL: Long dispatch time: 127 ms, for event type 2
[1693455992.136968][4839:4840] CHIP:BLE: Device 43:64:47:98:B2:6A does not look like a CHIP device.
[1693455992.139170][4839:4840] CHIP:BLE: Device 55:10:7D:B1:6C:94 does not look like a CHIP device.
[1693455992.144187][4839:4840] CHIP:BLE: Device 77:F8:C2:66:E0:EE does not look like a CHIP device.
[1693455992.190893][4839:4840] CHIP:BLE: Device 52:B6:FE:0D:52:8E does not look like a CHIP device.
[1693455992.192647][4839:4840] CHIP:BLE: Device 7B:3E:E8:FB:B9:E5 does not look like a CHIP device.
[1693455992.198519][4839:4840] CHIP:BLE: Device 4F:42:CC:FF:9D:AD does not look like a CHIP device.
[1693455992.237858][4839:4840] CHIP:BLE: Device 4A:97:7C:F4:F4:F1 does not look like a CHIP device.
[1693455992.244527][4839:4840] CHIP:BLE: Device D5:5B:3D:14:B3:8F does not look like a CHIP device.
[1693455992.302090][4839:4840] CHIP:BLE: Device 5E:1F:73:F2:C2:3F does not look like a CHIP device.
[1693455992.315487][4839:4840] CHIP:BLE: Device 35:29:5E:75:6B:ED does not look like a CHIP device.
[1693455992.385728][4839:4840] CHIP:BLE: Device 5A:92:DF:03:CE:2E does not look like a CHIP device.
[1693455992.447875][4839:4840] CHIP:BLE: Device 55:10:7D:B1:6C:94 does not look like a CHIP device.
[1693455992.461133][4839:4840] CHIP:BLE: Device 52:B6:FE:0D:52:8E does not look like a CHIP device.
[1693455992.476969][4839:4840] CHIP:BLE: Device 5F:03:20:5A:24:C4 does not look like a CHIP device.
[1693455992.535754][4839:4840] CHIP:BLE: Device 55:10:7D:B1:6C:94 does not look like a CHIP device.
[1693455992.562439][4839:4840] CHIP:BLE: Device 77:F8:C2:66:E0:EE does not look like a CHIP device.
[1693455992.657832][4839:4840] CHIP:BLE: Device 5A:92:DF:03:CE:2E does not look like a CHIP device.
[1693455992.675837][4839:4840] CHIP:BLE: Device C3:45:FB:8C:1A:33 does not look like a CHIP device.
[1693455992.739873][4839:4840] CHIP:BLE: Device 7B:3E:E8:FB:B9:E5 does not look like a CHIP device.
[1693455992.774767][4839:4840] CHIP:BLE: Device 4A:97:7C:F4:F4:F1 does not look like a CHIP device.
[1693455992.834091][4839:4840] CHIP:BLE: Device D5:F2:EA:48:13:47 does not look like a CHIP device.
[1693455992.886850][4839:4840] CHIP:BLE: Device 43:64:47:98:B2:6A does not look like a CHIP device.
[1693455992.930633][4839:4840] CHIP:BLE: Device 35:29:5E:75:6B:ED does not look like a CHIP device.
[1693455992.949098][4839:4840] CHIP:BLE: Device DB:9C:17:45:91:C0 does not look like a CHIP device.
[1693455992.983643][4839:4840] CHIP:BLE: Device 77:F8:C2:66:E0:EE does not look like a CHIP device.
[1693455993.034911][4839:4840] CHIP:BLE: Device 35:29:5E:75:6B:ED does not look like a CHIP device.
[1693455993.223787][4839:4840] CHIP:BLE: Device 47:D0:1D:75:59:8C does not look like a CHIP device.
[1693455993.233188][4839:4840] CHIP:BLE: Device E9:D8:C3:FF:DB:BE does not look like a CHIP device.
[1693455993.260438][4839:4840] CHIP:BLE: Device 52:B6:FE:0D:52:8E does not look like a CHIP device.
[1693455993.295423][4839:4840] CHIP:BLE: Device 7B:3E:E8:FB:B9:E5 does not look like a CHIP device.
[1693455993.305372][4839:4840] CHIP:BLE: Device 77:F8:C2:66:E0:EE does not look like a CHIP device.
[1693455993.321427][4839:4840] CHIP:BLE: Device 4A:97:7C:F4:F4:F1 does not look like a CHIP device.
[1693455993.428689][4839:4840] CHIP:BLE: Device 43:64:47:98:B2:6A does not look like a CHIP device.
[1693455993.483470][4839:4840] CHIP:BLE: Device 5A:92:DF:03:CE:2E does not look like a CHIP device.
[1693455993.560753][4839:4840] CHIP:BLE: Device 35:29:5E:75:6B:ED does not look like a CHIP device.
[1693455993.567996][4839:4840] CHIP:BLE: Device 4F:42:CC:FF:9D:AD does not look like a CHIP device.
[1693455993.749640][4839:4840] CHIP:BLE: Device D9:B1:89:CD:26:BC does not look like a CHIP device.
[1693455993.948121][4839:4840] CHIP:BLE: Device D2:D6:AF:FC:48:F7 does not look like a CHIP device.
[1693455993.948480][4839:4840] CHIP:BLE: Device F3:3D:4D:DB:DC:EE does not look like a CHIP device.
[1693455993.995691][4839:4840] CHIP:BLE: Device 35:29:5E:75:6B:ED does not look like a CHIP device.
[1693455994.125540][4839:4840] CHIP:BLE: Device 5A:92:DF:03:CE:2E does not look like a CHIP device.
[1693455994.193786][4839:4840] CHIP:BLE: Device 52:B6:FE:0D:52:8E does not look like a CHIP device.
[1693455994.308404][4839:4840] CHIP:BLE: Device 4F:42:CC:FF:9D:AD does not look like a CHIP device.
[1693455994.309306][4839:4840] CHIP:BLE: Device 5A:92:DF:03:CE:2E does not look like a CHIP device.
[1693455994.398003][4839:4840] CHIP:BLE: Device 4F:42:CC:FF:9D:AD does not look like a CHIP device.
[1693455994.677452][4839:4840] CHIP:BLE: Device C3:45:FB:8C:1A:33 does not look like a CHIP device.
[1693455994.837861][4839:4840] CHIP:BLE: Device D5:F2:EA:48:13:47 does not look like a CHIP device.
[1693455995.176084][4839:4840] CHIP:BLE: Device 77:F8:C2:66:E0:EE does not look like a CHIP device.
[1693455995.187870][4839:4840] CHIP:BLE: Device 02:67:D8:9B:04:BD does not look like a CHIP device.
[1693455995.227377][4839:4840] CHIP:BLE: Device 7B:3E:E8:FB:B9:E5 does not look like a CHIP device.
[1693455995.754318][4839:4840] CHIP:BLE: Device 52:B6:FE:0D:52:8E does not look like a CHIP device.
[1693455995.755287][4839:4840] CHIP:BLE: Device D9:B1:89:CD:26:BC does not look like a CHIP device.
[1693455995.761597][4839:4840] CHIP:BLE: Device CF:AD:81:30:E7:BB does not look like a CHIP device.
[1693455995.770820][4839:4840] CHIP:BLE: Device 4F:42:CC:FF:9D:AD does not look like a CHIP device.
[1693455995.802829][4839:4840] CHIP:BLE: Device 7B:3E:E8:FB:B9:E5 does not look like a CHIP device.
[1693455995.803547][4839:4840] CHIP:BLE: Device 77:F8:C2:66:E0:EE does not look like a CHIP device.
[1693455995.810845][4839:4840] CHIP:BLE: Device 02:67:D8:9B:04:BD does not look like a CHIP device.
[1693455996.677254][4839:4840] CHIP:BLE: Device 52:B6:FE:0D:52:8E does not look like a CHIP device.
[1693455996.678400][4839:4840] CHIP:BLE: Device C3:45:FB:8C:1A:33 does not look like a CHIP device.
[1693455997.478034][4839:4840] CHIP:BLE: Device E2:13:C2:7B:C0:70 does not look like a CHIP device.
[1693455998.197236][4839:4840] CHIP:BLE: Device 52:B6:FE:0D:52:8E does not look like a CHIP device.
[1693455998.446706][4839:4840] CHIP:BLE: Device 5A:92:DF:03:CE:2E does not look like a CHIP device.
[1693455998.625719][4839:4840] CHIP:BLE: Device 48:5F:74:67:2F:30 does not look like a CHIP device.
[1693455998.680855][4839:4840] CHIP:BLE: Device C3:45:FB:8C:1A:33 does not look like a CHIP device.
[1693455998.723092][4839:4840] CHIP:BLE: Device 5A:92:DF:03:CE:2E does not look like a CHIP device.
[1693455998.782864][4839:4840] CHIP:BLE: Device 52:B6:FE:0D:52:8E does not look like a CHIP device.
[1693455998.844840][4839:4840] CHIP:BLE: Device 4A:97:7C:F4:F4:F1 does not look like a CHIP device.
[1693455998.845869][4839:4840] CHIP:BLE: Device D5:F2:EA:48:13:47 does not look like a CHIP device.
[1693455999.001215][4839:4840] CHIP:BLE: New device scanned: CC:5E:B5:42:C3:48
[1693455999.001263][4839:4840] CHIP:BLE: Device discriminator match. Attempting to connect.
[1693456002.027697][4839:4841] CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:154: CHIP Error 0x00000032: Timeout
[1693456009.009391][4839:4841] CHIP:DL: HandlePlatformSpecificBLEEvent 16386
[1693456009.009445][4839:4841] CHIP:DIS: Closing all BLE connections
[1693456009.009636][4839:4840] CHIP:DL: FAIL: ConnectDevice : Operation was cancelled (19)
[1693456009.009853][4839:4841] CHIP:DL: HandlePlatformSpecificBLEEvent 16386
[1693456111.861977][4839:4839] CHIP:CTL: Shutting down the commissioner
[1693456111.862036][4839:4839] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1693456111.862062][4839:4839] CHIP:CTL: Shutting down the controller
[1693456111.862097][4839:4839] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1693456111.862125][4839:4839] CHIP:FP: Forgetting fabric 0x1
[1693456111.862163][4839:4839] CHIP:TS: Pending Last Known Good Time: 2023-07-11T07:53:58
[1693456111.862398][4839:4839] CHIP:TS: Previous Last Known Good Time: 2023-07-11T07:53:58
[1693456111.862427][4839:4839] CHIP:TS: Reverted Last Known Good Time to previous value
[1693456111.862470][4839:4839] CHIP:CTL: Shutting down the commissioner
[1693456111.862498][4839:4839] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1693456111.862522][4839:4839] CHIP:CTL: Shutting down the controller
[1693456111.862541][4839:4839] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1693456111.863739][4839:4839] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1693456111.863833][4839:4839] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1693456111.863882][4839:4839] CHIP:FP: Shutting down FabricTable
[1693456111.863918][4839:4839] CHIP:TS: Pending Last Known Good Time: 2023-07-11T07:53:58
[1693456111.864103][4839:4839] CHIP:TS: Previous Last Known Good Time: 2023-07-11T07:53:58
[1693456111.864126][4839:4839] CHIP:TS: Reverted Last Known Good Time to previous value
[1693456111.864355][4839:4839] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-v57lyA)
[1693456111.865010][4839:4839] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1693456111.865071][4839:4839] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1693456111.865095][4839:4839] CHIP:DL: Inet Layer shutdown
[1693456111.865114][4839:4839] CHIP:DL: BLE shutdown
[1693456111.865685][4839:4839] CHIP:DL: System Layer shutdown
[1693456111.866303][4839:4839] CHIP:TOO: Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:537: CHIP Error 0x00000032: Timeout

[AHaug]

Hi,

Thanks for the logs, I will have a look at them. Just a quick tip for future log-pasting: You can use the insert code function to add logs so the ticket becomes easier to read

1. Are you debugging the application while you were fetching the logs? The debug session does most likely cause timing issues which the Soft Device does not handle very well, which is probably why you see the softdevice assert as well as the advertising issues. Do you see the same fault when you're not debugging?
2. Could you verify if you are able to reproduce this on a 52840DK, 5340DK or 7002DK?

Kind regards,
Andreas

[DoubleAmaing]

Hi，

Thank you for your guidance.

1. I don't have a Debug, my process is:

Download the program and connect to RTT;

2. Sorry, our company has not received any DK.

We have made a small system ourselves, using "E73-2G4M08S1C" and powered by 3.3V；

I use light_ Blub,  prj.conf

[DoubleAmaing]

Hi

E73-2G4M08S1C"included 52840,and

XT1=32MHZ

[AHaug]

Are you able to run basic Bluetooth samples on the module?

Kind regards,
Andreas

[DoubleAmaing]

Thank you for your help. I feel closer to solving the problem.

I tested using the Bluetooth example and it was not connected, as follows:

Tool: nRF connect for Mobile (Android phone), "Bluetooth: Peripheral Status ";

It has the following error prompt (nRF RTT terminal):

I: Identity: CC:68:EF:6F:CF:85 (random)
I: HCI: version 5.4 (0x0d) revision 0x1077, manufacturer 0x0059
I: LMP: version 5.4 (0x0d) subver 0x1077
Advertising successfully started
Connected
Disconnected (reason 62)

I think it is necessary for me to explain the download process and confirm if I am missing any steps:

1. Vs code “Open an exiting application”, to select "“Bluetooth: Peripheral Status”"

2. Add the RTT enable command to the file prj.conf:

# Reduce application size
CONFIG_USE_SEGGER_RTT=y
CONFIG_RTT_CONSOLE=y
CONFIG_UART_CONSOLE=n

3. "Edit Build configuration" ,and build

1.

4

4. "Flash"and “Connect RTT”

[DoubleAmaing]

Complete prompt：

SEGGER J-Link V7.88j - Real time terminal output
SEGGER J-Link V10.1, SN=600105955
Process: JLinkExe
*** Booting Zephyr OS build v3.3.99-ncs1-1 ***
Starting Bluetooth Peripheral Status example
I: 8 Sectors of 4096 bytes
I: alloc wra: 0, ea0
I: data wra: 0, 11c
I: SoftDevice Controller build revision: 
I: e0 7e 2e c1 5e 05 85 23 |.~..^..#
I: 46 15 dc fa 8e 29 7d 70 |F....)}p
I: 10 93 a5 fc             |....    
I: HW Platform: Nordic Semiconductor (0x0002)
I: HW Variant: nRF52x (0x0002)
I: Firmware: Standard Bluetooth controller (0x00) Version 224.11902 Build 2231721665
I: No ID address. App must call settings_load()
Bluetooth initialized
I: Identity: CC:68:EF:6F:CF:85 (random)
I: HCI: version 5.4 (0x0d) revision 0x1077, manufacturer 0x0059
I: LMP: version 5.4 (0x0d) subver 0x1077
Advertising successfully started
Connected
Disconnected (reason 62)

[DoubleAmaing]

Hi, please allow me to update again.

I have successfully connected, but I don't understand why I am doing this:

I referred to the link: nRF5340 Peripheral BLE connections always fail with reason 0x3e (62) 

I have added the following content to prjconf:

CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC=y

CONFIG_SOC_ENABLE_LFXO=n

Bluetooth example successfully connected, I will add

this content to the subject, Light_ Blub;
The connection was also successful!

I can check the customer board on the border router。

The following is the distribution network information.

Was it successful?

Could you briefly explain the reason to me？

[DoubleAmaing]

~/chip-tool/chip-tool-linux_x64$ ./chip-tool-debug pairing ble-thread 1 hex:0e08000000000001000035060004001fffe00708fd8cbda7fa852afe0c0402a0f7f8051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f0410445f2b5ca6f2a93a55ce570a70efeecb000300000f0208111111112222222201021234 20202021 3840
[1694055304.311745][30046:30046] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1694055304.311808][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_kvs-TFU4T8)
[1694055304.311855][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs)
[1694055304.312594][30046:30046] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1694055304.312636][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-fxxXQ9)
[1694055304.312674][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1694055304.312699][30046:30046] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1694055304.312730][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_config.ini-7js789)
[1694055304.312764][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1694055304.312787][30046:30046] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1694055304.312817][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-78No39)
[1694055304.312851][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1694055304.312907][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-gBsRT8)
[1694055304.313003][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1694055304.313016][30046:30046] CHIP:DL: NVS set: chip-factory/unique-id = "B71EC24242E794D6"
[1694055304.313053][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-KF2589)
[1694055304.313145][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1694055304.313159][30046:30046] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1)
[1694055304.313196][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-UQMZy7)
[1694055304.313292][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1694055304.313307][30046:30046] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001)
[1694055304.313342][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-NXIlra)
[1694055304.313418][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1694055304.313431][30046:30046] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1)
[1694055304.313469][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-BRijE6)
[1694055304.313554][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1694055304.313567][30046:30046] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1694055304.313604][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-SYYNf7)
[1694055304.313693][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1694055304.313706][30046:30046] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0)
[1694055304.313738][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_config.ini-Ubeqt7)
[1694055304.313813][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1694055304.313825][30046:30046] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0)
[1694055304.313864][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_config.ini-xp0AD7)
[1694055304.313947][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1694055304.313959][30046:30046] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2)
[1694055304.314156][30046:30046] CHIP:DL: Got Ethernet interface: enp4s0
[1694055304.314300][30046:30046] CHIP:DL: Found the primary Ethernet interface:enp4s0
[1694055304.314445][30046:30046] CHIP:DL: Got WiFi interface: wlp5s0
[1694055304.314599][30046:30046] CHIP:DL: Found the primary WiFi interface:wlp5s0
[1694055304.314848][30046:30046] CHIP:IN: UDP::Init bind&listen port=0
[1694055304.314875][30046:30046] CHIP:IN: UDP::Init bound to port=35683
[1694055304.314883][30046:30046] CHIP:IN: UDP::Init bind&listen port=0
[1694055304.314904][30046:30046] CHIP:IN: UDP::Init bound to port=37388
[1694055304.314910][30046:30046] CHIP:IN: BLEBase::Init - setting/overriding transport
[1694055304.314916][30046:30046] CHIP:IN: TransportMgr initialized
[1694055304.314943][30046:30046] CHIP:FP: Initializing FabricTable from persistent storage
[1694055304.314982][30046:30046] CHIP:TS: Last Known Good Time: [unknown]
[1694055304.314990][30046:30046] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-07-11T07:53:58
[1694055304.315774][30046:30046] CHIP:ZCL: Using ZAP configuration...
[1694055304.317972][30046:30046] CHIP:DL: Avahi client registered
[1694055304.318770][30046:30046] CHIP:CTL: System State Initialized...
[1694055304.318994][30046:30046] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1694055304.319015][30046:30046] CHIP:CTL: Setting attestation nonce to random value
[1694055304.319023][30046:30046] CHIP:CTL: Setting CSR nonce to random value
[1694055304.319101][30046:30048] CHIP:DL: CHIP task running
[1694055304.319152][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1694055304.319287][30046:30048] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1694055304.319298][30046:30048] CHIP:CTL: Setting attestation nonce to random value
[1694055304.319305][30046:30048] CHIP:CTL: Setting CSR nonce to random value
[1694055304.319361][30046:30048] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1694055304.324020][30046:30048] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1694055304.331714][30046:30048] CHIP:CTL: Generating RCAC
[1694055304.364204][30046:30048] CHIP:CTL: Generating ICAC
[1694055304.372494][30046:30048] CHIP:CTL: Generating NOC
[1694055304.378598][30046:30048] CHIP:FP: Validating NOC chain
[1694055304.395899][30046:30048] CHIP:FP: NOC chain validation successful
[1694055304.396447][30046:30048] CHIP:FP: Added new fabric at index: 0x1
[1694055304.396454][30046:30048] CHIP:FP: Assigned compressed fabric ID: 0xE6F06EAE27CA3AAD, node ID: 0x000000000001B669
[1694055304.396461][30046:30048] CHIP:TS: Last Known Good Time: 2023-07-11T07:53:58
[1694055304.396465][30046:30048] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1694055304.396469][30046:30048] CHIP:TS: Retaining current Last Known Good Time
[1694055304.416159][30046:30048] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1694055304.417830][30046:30048] CHIP:TS: Committing Last Known Good Time to storage: 2023-07-11T07:53:58
[1694055304.419126][30046:30048] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: E6F06EAE27CA3AAD)
[1694055304.434606][30046:30048] CHIP:CTL: Setting thread operational dataset from parameters
[1694055304.434627][30046:30048] CHIP:CTL: Setting attestation nonce to random value
[1694055304.434639][30046:30048] CHIP:CTL: Setting CSR nonce to random value
[1694055304.434650][30046:30048] CHIP:CTL: Commission called for node ID 0x0000000000000001
[1694055304.434669][30046:30048] CHIP:DL: Long dispatch time: 116 ms, for event type 2
[1694055304.437492][30046:30047] CHIP:DL: TRACE: Bus acquired for name C-755e
[1694055304.440943][30046:30048] CHIP:DL: PlatformBlueZInit init success
[1694055304.443443][30046:30047] CHIP:BLE: BLE removing known devices.
[1694055304.444067][30046:30047] CHIP:BLE: BLE initiating scan.
[1694055304.591694][30046:30048] CHIP:DL: Long dispatch time: 157 ms, for event type 2
[1694055304.613099][30046:30047] CHIP:BLE: New device scanned: EE:05:FD:CE:F6:42
[1694055304.613146][30046:30047] CHIP:BLE: Device discriminator match. Attempting to connect.
[1694055304.774978][30046:30047] CHIP:DL: ConnectDevice complete
[1694055305.865716][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.865829][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.865908][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0001
[1694055305.865968][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866026][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0001
[1694055305.866074][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866128][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0001
[1694055305.866175][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866246][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0001
[1694055305.866301][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866367][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0001
[1694055305.866425][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866477][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0001
[1694055305.866523][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866590][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866645][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866683][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866760][30046:30047] CHIP:DL: Char1 /org/bluez/hci0/dev_EE_05_FD_CE_F6_42/service0010
[1694055305.866832][30046:30047] CHIP:DL: New BLE connection 0x7fba540481d0, device EE:05:FD:CE:F6:42, path /org/bluez/hci0/dev_EE_05_FD_CE_F6_42
[1694055305.866993][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16385
[1694055305.867040][30046:30048] CHIP:DIS: Closing all BLE connections
[1694055305.867161][30046:30048] CHIP:IN: BleConnectionComplete: endPoint 0x556a9a5ce3c0
[1694055305.867897][30046:30048] CHIP:IN: SecureSession[0x7fba4c010d00]: Allocated Type:1 LSID:28753
[1694055305.867960][30046:30048] CHIP:SC: Assigned local session key ID 28753
[1694055305.868093][30046:30048] CHIP:EM: <<< [E:3655i S:0 M:112192125] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[1694055305.868134][30046:30048] CHIP:IN: (U) Sending msg 112192125 to IP address 'BLE'
[1694055305.868156][30046:30048] CHIP:IN: Message appended to BLE send queue
[1694055305.868172][30046:30048] CHIP:SC: Sent PBKDF param request
[1694055306.303696][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055306.396397][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1694055306.396454][30046:30048] CHIP:BLE: subscribe complete, ep = 0x556a9a5ce3c0
[1694055306.396670][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055306.396764][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055306.396797][30046:30048] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4
[1694055306.396823][30046:30048] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244.
[1694055306.396843][30046:30048] CHIP:BLE: local and remote recv window size = 5
[1694055306.397447][30046:30048] CHIP:IN: BLE EndPoint 0x556a9a5ce3c0 Connection Complete
[1694055306.483798][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055306.486673][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055306.486798][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055306.486929][30046:30048] CHIP:EM: >>> [E:3655i S:0 M:199762175] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
[1694055306.486975][30046:30048] CHIP:EM: Found matching exchange: 3655i, Delegate: 0x7fba4c00ce00
[1694055306.487031][30046:30048] CHIP:SC: Received PBKDF param response
[1694055306.487150][30046:30048] CHIP:SC: Peer assigned session ID 6457
[1694055306.487202][30046:30048] CHIP:SC: Found MRP parameters in the message
[1694055306.544764][30046:30048] CHIP:EM: <<< [E:3655i S:0 M:112192126] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
[1694055306.544806][30046:30048] CHIP:IN: (U) Sending msg 112192126 to IP address 'BLE'
[1694055306.545076][30046:30048] CHIP:SC: Sent spake2p msg1
[1694055306.618920][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055308.241525][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055308.241844][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055308.241995][30046:30048] CHIP:EM: >>> [E:3655i S:0 M:199762176] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
[1694055308.242038][30046:30048] CHIP:EM: Found matching exchange: 3655i, Delegate: 0x7fba4c00ce00
[1694055308.242098][30046:30048] CHIP:SC: Received spake2p msg2
[1694055308.291965][30046:30048] CHIP:EM: <<< [E:3655i S:0 M:112192127] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
[1694055308.291998][30046:30048] CHIP:IN: (U) Sending msg 112192127 to IP address 'BLE'
[1694055308.292345][30046:30048] CHIP:SC: Sent spake2p msg3
[1694055308.373586][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055308.375558][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055308.375869][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055308.376017][30046:30048] CHIP:EM: >>> [E:3655i S:0 M:199762177] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1694055308.376056][30046:30048] CHIP:EM: Found matching exchange: 3655i, Delegate: 0x7fba4c00ce00
[1694055308.376191][30046:30048] CHIP:SC: SecureSession[0x7fba4c010d00]: Moving from state 'kEstablishing' --> 'kActive'
[1694055308.376220][30046:30048] CHIP:IN: SecureSession[0x7fba4c010d00]: Activated - Type:1 LSID:28753
[1694055308.376241][30046:30048] CHIP:IN: New secure session activated for device <FFFFFFFB00000000, 0>, LSID:28753 PSID:6457!
[1694055308.376270][30046:30048] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1694055308.376289][30046:30048] CHIP:TOO: Pairing Success
[1694055308.376306][30046:30048] CHIP:TOO: PASE establishment successful
[1694055308.376369][30046:30048] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1694055308.376399][30046:30048] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo'
[1694055308.376420][30046:30048] CHIP:CTL: Sending request for commissioning information
[1694055308.376505][30046:30048] CHIP:DMG: SendReadRequest ReadClient[0x7fba4c011800]: Sending Read Request
[1694055308.376721][30046:30048] CHIP:EM: <<< [E:3656i S:28753 M:35424720] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
[1694055308.376769][30046:30048] CHIP:IN: (S) Sending msg 35424720 on secure session with LSID: 28753
[1694055308.377241][30046:30048] CHIP:DMG: MoveToState ReadClient[0x7fba4c011800]: Moving to [AwaitingIn]
[1694055308.463560][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055308.468810][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055308.469094][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055308.556265][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055308.556591][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055308.556733][30046:30048] CHIP:EM: >>> [E:3656i S:28753 M:262639350] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
[1694055308.556777][30046:30048] CHIP:EM: Found matching exchange: 3656i, Delegate: 0x7fba4c011810
[1694055308.556923][30046:30048] CHIP:DMG: ReportDataMessage =
[1694055308.556953][30046:30048] CHIP:DMG: {
[1694055308.556975][30046:30048] CHIP:DMG:     AttributeReportIBs =
[1694055308.557016][30046:30048] CHIP:DMG:     [
[1694055308.557040][30046:30048] CHIP:DMG:         AttributeReportIB =
[1694055308.557079][30046:30048] CHIP:DMG:         {
[1694055308.557108][30046:30048] CHIP:DMG:             AttributeDataIB =
[1694055308.557136][30046:30048] CHIP:DMG:             {
[1694055308.557162][30046:30048] CHIP:DMG:                 DataVersion = 0x9849a6e4,
[1694055308.557181][30046:30048] CHIP:DMG:                 AttributePathIB =
[1694055308.557208][30046:30048] CHIP:DMG:                 {
[1694055308.557237][30046:30048] CHIP:DMG:                     Endpoint = 0x0,
[1694055308.557268][30046:30048] CHIP:DMG:                     Cluster = 0x31,
[1694055308.557297][30046:30048] CHIP:DMG:                     Attribute = 0x0000_0003,
[1694055308.557324][30046:30048] CHIP:DMG:                 }
[1694055308.557358][30046:30048] CHIP:DMG:                     
[1694055308.557393][30046:30048] CHIP:DMG:                 Data = 20,
[1694055308.557419][30046:30048] CHIP:DMG:             },
[1694055308.557456][30046:30048] CHIP:DMG:             
[1694055308.557476][30046:30048] CHIP:DMG:         },
[1694055308.557523][30046:30048] CHIP:DMG:         
[1694055308.557547][30046:30048] CHIP:DMG:         AttributeReportIB =
[1694055308.557586][30046:30048] CHIP:DMG:         {
[1694055308.557606][30046:30048] CHIP:DMG:             AttributeDataIB =
[1694055308.557629][30046:30048] CHIP:DMG:             {
[1694055308.557654][30046:30048] CHIP:DMG:                 DataVersion = 0x90b177e9,
[1694055308.557675][30046:30048] CHIP:DMG:                 AttributePathIB =
[1694055308.557700][30046:30048] CHIP:DMG:                 {
[1694055308.557723][30046:30048] CHIP:DMG:                     Endpoint = 0x0,
[1694055308.557747][30046:30048] CHIP:DMG:                     Cluster = 0x28,
[1694055308.557775][30046:30048] CHIP:DMG:                     Attribute = 0x0000_0004,
[1694055308.557797][30046:30048] CHIP:DMG:                 }
[1694055308.557825][30046:30048] CHIP:DMG:                     
[1694055308.557852][30046:30048] CHIP:DMG:                 Data = 32773,
[1694055308.557876][30046:30048] CHIP:DMG:             },
[1694055308.557912][30046:30048] CHIP:DMG:             
[1694055308.557936][30046:30048] CHIP:DMG:         },
[1694055308.557979][30046:30048] CHIP:DMG:         
[1694055308.557997][30046:30048] CHIP:DMG:         AttributeReportIB =
[1694055308.558028][30046:30048] CHIP:DMG:         {
[1694055308.558047][30046:30048] CHIP:DMG:             AttributeDataIB =
[1694055308.558068][30046:30048] CHIP:DMG:             {
[1694055308.558090][30046:30048] CHIP:DMG:                 DataVersion = 0x90b177e9,
[1694055308.558111][30046:30048] CHIP:DMG:                 AttributePathIB =
[1694055308.558133][30046:30048] CHIP:DMG:                 {
[1694055308.558155][30046:30048] CHIP:DMG:                     Endpoint = 0x0,
[1694055308.558179][30046:30048] CHIP:DMG:                     Cluster = 0x28,
[1694055308.558202][30046:30048] CHIP:DMG:                     Attribute = 0x0000_0002,
[1694055308.558223][30046:30048] CHIP:DMG:                 }
[1694055308.558249][30046:30048] CHIP:DMG:                     
[1694055308.558273][30046:30048] CHIP:DMG:                 Data = 65521,
[1694055308.558293][30046:30048] CHIP:DMG:             },
[1694055308.558321][30046:30048] CHIP:DMG:             
[1694055308.558339][30046:30048] CHIP:DMG:         },
[1694055308.558380][30046:30048] CHIP:DMG:         
[1694055308.558398][30046:30048] CHIP:DMG:         AttributeReportIB =
[1694055308.558428][30046:30048] CHIP:DMG:         {
[1694055308.558446][30046:30048] CHIP:DMG:             AttributeDataIB =
[1694055308.558467][30046:30048] CHIP:DMG:             {
[1694055308.558489][30046:30048] CHIP:DMG:                 DataVersion = 0x37aa8bc9,
[1694055308.558509][30046:30048] CHIP:DMG:                 AttributePathIB =
[1694055308.558531][30046:30048] CHIP:DMG:                 {
[1694055308.558553][30046:30048] CHIP:DMG:                     Endpoint = 0x0,
[1694055308.558576][30046:30048] CHIP:DMG:                     Cluster = 0x30,
[1694055308.558600][30046:30048] CHIP:DMG:                     Attribute = 0x0000_0003,
[1694055308.558620][30046:30048] CHIP:DMG:                 }
[1694055308.558647][30046:30048] CHIP:DMG:                     
[1694055308.558670][30046:30048] CHIP:DMG:                 Data = 0,
[1694055308.558690][30046:30048] CHIP:DMG:             },
[1694055308.558718][30046:30048] CHIP:DMG:             
[1694055308.558736][30046:30048] CHIP:DMG:         },
[1694055308.558776][30046:30048] CHIP:DMG:         
[1694055308.558794][30046:30048] CHIP:DMG:         AttributeReportIB =
[1694055308.558825][30046:30048] CHIP:DMG:         {
[1694055308.558843][30046:30048] CHIP:DMG:             AttributeDataIB =
[1694055308.558864][30046:30048] CHIP:DMG:             {
[1694055308.558886][30046:30048] CHIP:DMG:                 DataVersion = 0x37aa8bc9,
[1694055308.558906][30046:30048] CHIP:DMG:                 AttributePathIB =
[1694055308.558928][30046:30048] CHIP:DMG:                 {
[1694055308.558950][30046:30048] CHIP:DMG:                     Endpoint = 0x0,
[1694055308.558973][30046:30048] CHIP:DMG:                     Cluster = 0x30,
[1694055308.558996][30046:30048] CHIP:DMG:                     Attribute = 0x0000_0002,
[1694055308.559017][30046:30048] CHIP:DMG:                 }
[1694055308.559043][30046:30048] CHIP:DMG:                     
[1694055308.559068][30046:30048] CHIP:DMG:                 Data = 0,
[1694055308.559087][30046:30048] CHIP:DMG:             },
[1694055308.559115][30046:30048] CHIP:DMG:             
[1694055308.559134][30046:30048] CHIP:DMG:         },
[1694055308.559177][30046:30048] CHIP:DMG:         
[1694055308.559195][30046:30048] CHIP:DMG:         AttributeReportIB =
[1694055308.559228][30046:30048] CHIP:DMG:         {
[1694055308.559247][30046:30048] CHIP:DMG:             AttributeDataIB =
[1694055308.559268][30046:30048] CHIP:DMG:             {
[1694055308.559289][30046:30048] CHIP:DMG:                 DataVersion = 0x37aa8bc9,
[1694055308.559310][30046:30048] CHIP:DMG:                 AttributePathIB =
[1694055308.559346][30046:30048] CHIP:DMG:                 {
[1694055308.559375][30046:30048] CHIP:DMG:                     Endpoint = 0x0,
[1694055308.559411][30046:30048] CHIP:DMG:                     Cluster = 0x30,
[1694055308.559441][30046:30048] CHIP:DMG:                     Attribute = 0x0000_0001,
[1694055308.559465][30046:30048] CHIP:DMG:                 }
[1694055308.559504][30046:30048] CHIP:DMG:                     
[1694055308.559529][30046:30048] CHIP:DMG:                 Data =
[1694055308.559552][30046:30048] CHIP:DMG:                 {
[1694055308.559576][30046:30048] CHIP:DMG:                     0x0 = 60,
[1694055308.559601][30046:30048] CHIP:DMG:                     0x1 = 900,
[1694055308.559624][30046:30048] CHIP:DMG:                 },
[1694055308.559643][30046:30048] CHIP:DMG:             },
[1694055308.559675][30046:30048] CHIP:DMG:             
[1694055308.559693][30046:30048] CHIP:DMG:         },
[1694055308.559737][30046:30048] CHIP:DMG:         
[1694055308.559756][30046:30048] CHIP:DMG:         AttributeReportIB =
[1694055308.559786][30046:30048] CHIP:DMG:         {
[1694055308.559805][30046:30048] CHIP:DMG:             AttributeDataIB =
[1694055308.559826][30046:30048] CHIP:DMG:             {
[1694055308.559847][30046:30048] CHIP:DMG:                 DataVersion = 0x37aa8bc9,
[1694055308.559867][30046:30048] CHIP:DMG:                 AttributePathIB =
[1694055308.559889][30046:30048] CHIP:DMG:                 {
[1694055308.559912][30046:30048] CHIP:DMG:                     Endpoint = 0x0,
[1694055308.559936][30046:30048] CHIP:DMG:                     Cluster = 0x30,
[1694055308.559959][30046:30048] CHIP:DMG:                     Attribute = 0x0000_0000,
[1694055308.559980][30046:30048] CHIP:DMG:                 }
[1694055308.560006][30046:30048] CHIP:DMG:                     
[1694055308.560030][30046:30048] CHIP:DMG:                 Data = 0,
[1694055308.560049][30046:30048] CHIP:DMG:             },
[1694055308.560077][30046:30048] CHIP:DMG:             
[1694055308.560096][30046:30048] CHIP:DMG:         },
[1694055308.560136][30046:30048] CHIP:DMG:         
[1694055308.560154][30046:30048] CHIP:DMG:         AttributeReportIB =
[1694055308.560185][30046:30048] CHIP:DMG:         {
[1694055308.560210][30046:30048] CHIP:DMG:             AttributeDataIB =
[1694055308.560234][30046:30048] CHIP:DMG:             {
[1694055308.560263][30046:30048] CHIP:DMG:                 DataVersion = 0x9849a6e4,
[1694055308.560290][30046:30048] CHIP:DMG:                 AttributePathIB =
[1694055308.560357][30046:30048] CHIP:DMG:                 {
[1694055308.560389][30046:30048] CHIP:DMG:                     Endpoint = 0x0,
[1694055308.560417][30046:30048] CHIP:DMG:                     Cluster = 0x31,
[1694055308.560449][30046:30048] CHIP:DMG:                     Attribute = 0x0000_FFFC,
[1694055308.560474][30046:30048] CHIP:DMG:                 }
[1694055308.560507][30046:30048] CHIP:DMG:                     
[1694055308.560535][30046:30048] CHIP:DMG:                 Data = 2,
[1694055308.560557][30046:30048] CHIP:DMG:             },
[1694055308.560588][30046:30048] CHIP:DMG:             
[1694055308.560609][30046:30048] CHIP:DMG:         },
[1694055308.560640][30046:30048] CHIP:DMG:         
[1694055308.560660][30046:30048] CHIP:DMG:     ],
[1694055308.560767][30046:30048] CHIP:DMG:     
[1694055308.560792][30046:30048] CHIP:DMG:     SuppressResponse = true,
[1694055308.560815][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055308.560834][30046:30048] CHIP:DMG: }
[1694055308.562315][30046:30048] CHIP:CTL: ----- NetworkCommissioning Features: has Thread. endpointid = 0
[1694055308.562378][30046:30048] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo'
[1694055308.562399][30046:30048] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe'
[1694055308.562419][30046:30048] CHIP:CTL: Performing next commissioning step 'ArmFailSafe'
[1694055308.562455][30046:30048] CHIP:CTL: Arming failsafe (60 seconds)
[1694055308.562522][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055308.562559][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055308.562646][30046:30048] CHIP:EM: <<< [E:3657i S:28753 M:35424721] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055308.562683][30046:30048] CHIP:IN: (S) Sending msg 35424721 on secure session with LSID: 28753
[1694055308.563122][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055308.643142][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055308.645444][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055308.645637][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055308.645748][30046:30048] CHIP:EM: >>> [E:3657i S:28753 M:262639351] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055308.645783][30046:30048] CHIP:EM: Found matching exchange: 3657i, Delegate: 0x7fba5404ae38
[1694055308.645814][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055308.645859][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055308.645876][30046:30048] CHIP:DMG: {
[1694055308.645894][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055308.645912][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055308.645951][30046:30048] CHIP:DMG:     [
[1694055308.645972][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055308.646004][30046:30048] CHIP:DMG:         {
[1694055308.646023][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055308.646046][30046:30048] CHIP:DMG:             {
[1694055308.646066][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055308.646093][30046:30048] CHIP:DMG:                 {
[1694055308.646116][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055308.646139][30046:30048] CHIP:DMG:                     ClusterId = 0x30,
[1694055308.646162][30046:30048] CHIP:DMG:                     CommandId = 0x1,
[1694055308.646185][30046:30048] CHIP:DMG:                 },
[1694055308.646213][30046:30048] CHIP:DMG:                 
[1694055308.646234][30046:30048] CHIP:DMG:                 CommandFields =
[1694055308.646269][30046:30048] CHIP:DMG:                 {
[1694055308.646298][30046:30048] CHIP:DMG:                     0x0 = 0,
[1694055308.646331][30046:30048] CHIP:DMG:                     0x1 = "" (0 chars),
[1694055308.646357][30046:30048] CHIP:DMG:                 },
[1694055308.646375][30046:30048] CHIP:DMG:             },
[1694055308.646404][30046:30048] CHIP:DMG:             
[1694055308.646427][30046:30048] CHIP:DMG:         },
[1694055308.646456][30046:30048] CHIP:DMG:         
[1694055308.646470][30046:30048] CHIP:DMG:     ],
[1694055308.646502][30046:30048] CHIP:DMG:     
[1694055308.646520][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055308.646537][30046:30048] CHIP:DMG: },
[1694055308.646606][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1694055308.646650][30046:30048] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1694055308.646669][30046:30048] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe'
[1694055308.646682][30046:30048] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1694055308.646704][30046:30048] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory'
[1694055308.646717][30046:30048] CHIP:CTL: Setting Regulatory Config
[1694055308.646730][30046:30048] CHIP:CTL: Device does not support configurable regulatory location
[1694055308.646777][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055308.646798][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055308.646854][30046:30048] CHIP:EM: <<< [E:3658i S:28753 M:35424722] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055308.646881][30046:30048] CHIP:IN: (S) Sending msg 35424722 on secure session with LSID: 28753
[1694055308.647205][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055308.647262][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055308.733608][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055308.736452][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055308.736756][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055308.736944][30046:30048] CHIP:EM: >>> [E:3658i S:28753 M:262639352] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055308.737002][30046:30048] CHIP:EM: Found matching exchange: 3658i, Delegate: 0x7fba4c011408
[1694055308.737051][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055308.737130][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055308.737168][30046:30048] CHIP:DMG: {
[1694055308.737205][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055308.737240][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055308.737294][30046:30048] CHIP:DMG:     [
[1694055308.737329][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055308.737380][30046:30048] CHIP:DMG:         {
[1694055308.737412][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055308.737453][30046:30048] CHIP:DMG:             {
[1694055308.737486][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055308.737531][30046:30048] CHIP:DMG:                 {
[1694055308.737570][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055308.737608][30046:30048] CHIP:DMG:                     ClusterId = 0x30,
[1694055308.737647][30046:30048] CHIP:DMG:                     CommandId = 0x3,
[1694055308.737682][30046:30048] CHIP:DMG:                 },
[1694055308.737727][30046:30048] CHIP:DMG:                 
[1694055308.737765][30046:30048] CHIP:DMG:                 CommandFields =
[1694055308.737802][30046:30048] CHIP:DMG:                 {
[1694055308.737845][30046:30048] CHIP:DMG:                     0x0 = 0,
[1694055308.737889][30046:30048] CHIP:DMG:                     0x1 = "" (0 chars),
[1694055308.737944][30046:30048] CHIP:DMG:                 },
[1694055308.737998][30046:30048] CHIP:DMG:             },
[1694055308.738046][30046:30048] CHIP:DMG:             
[1694055308.738079][30046:30048] CHIP:DMG:         },
[1694055308.738131][30046:30048] CHIP:DMG:         
[1694055308.738164][30046:30048] CHIP:DMG:     ],
[1694055308.738211][30046:30048] CHIP:DMG:     
[1694055308.738248][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055308.738278][30046:30048] CHIP:DMG: },
[1694055308.738396][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1694055308.739071][30046:30048] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0
[1694055308.739131][30046:30048] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory'
[1694055308.739181][30046:30048] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
[1694055308.739214][30046:30048] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest'
[1694055308.739243][30046:30048] CHIP:CTL: Sending request for PAI certificate
[1694055308.739274][30046:30048] CHIP:CTL: Sending Certificate Chain request to 0x7fba4c00cdb0 device
[1694055308.739355][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055308.739881][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055308.740023][30046:30048] CHIP:EM: <<< [E:3659i S:28753 M:35424723] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055308.740077][30046:30048] CHIP:IN: (S) Sending msg 35424723 on secure session with LSID: 28753
[1694055308.740758][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055308.740844][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055308.822701][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055308.826684][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055308.826728][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055308.916207][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055308.916344][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055309.004404][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055309.004579][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055309.004687][30046:30048] CHIP:EM: >>> [E:3659i S:28753 M:262639353] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055309.004716][30046:30048] CHIP:EM: Found matching exchange: 3659i, Delegate: 0x7fba5404ae38
[1694055309.004742][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055309.004773][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055309.004784][30046:30048] CHIP:DMG: {
[1694055309.004797][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055309.004808][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055309.004827][30046:30048] CHIP:DMG:     [
[1694055309.004837][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055309.004856][30046:30048] CHIP:DMG:         {
[1694055309.004867][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055309.004881][30046:30048] CHIP:DMG:             {
[1694055309.004892][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055309.004909][30046:30048] CHIP:DMG:                 {
[1694055309.004922][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055309.004935][30046:30048] CHIP:DMG:                     ClusterId = 0x3e,
[1694055309.004949][30046:30048] CHIP:DMG:                     CommandId = 0x3,
[1694055309.004960][30046:30048] CHIP:DMG:                 },
[1694055309.004975][30046:30048] CHIP:DMG:                 
[1694055309.004987][30046:30048] CHIP:DMG:                 CommandFields =
[1694055309.005001][30046:30048] CHIP:DMG:                 {
[1694055309.005013][30046:30048] CHIP:DMG:                     0x0 = [
[1694055309.005145][30046:30048] CHIP: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
[1694055309.005191][30046:30048] CHIP:DMG:                     ] (463 bytes)
[1694055309.005207][30046:30048] CHIP:DMG:                 },
[1694055309.005219][30046:30048] CHIP:DMG:             },
[1694055309.005236][30046:30048] CHIP:DMG:             
[1694055309.005281][30046:30048] CHIP:DMG:         },
[1694055309.005305][30046:30048] CHIP:DMG:         
[1694055309.005317][30046:30048] CHIP:DMG:     ],
[1694055309.005333][30046:30048] CHIP:DMG:     
[1694055309.005342][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055309.005354][30046:30048] CHIP:DMG: },
[1694055309.005401][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1694055309.005422][30046:30048] CHIP:CTL: Received certificate chain from the device
[1694055309.005445][30046:30048] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest'
[1694055309.005459][30046:30048] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1694055309.005474][30046:30048] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest'
[1694055309.005491][30046:30048] CHIP:CTL: Sending request for DAC certificate
[1694055309.005504][30046:30048] CHIP:CTL: Sending Certificate Chain request to 0x7fba4c00cdb0 device
[1694055309.005553][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055309.005570][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055309.005633][30046:30048] CHIP:EM: <<< [E:3660i S:28753 M:35424724] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055309.005656][30046:30048] CHIP:IN: (S) Sending msg 35424724 on secure session with LSID: 28753
[1694055309.005971][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055309.006018][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055309.094359][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055309.097803][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055309.098080][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055309.232576][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055309.232862][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055309.365160][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055309.365432][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055309.365627][30046:30048] CHIP:EM: >>> [E:3660i S:28753 M:262639354] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055309.365684][30046:30048] CHIP:EM: Found matching exchange: 3660i, Delegate: 0x7fba5404b198
[1694055309.365733][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055309.365808][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055309.365846][30046:30048] CHIP:DMG: {
[1694055309.365868][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055309.365895][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055309.365930][30046:30048] CHIP:DMG:     [
[1694055309.365962][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055309.365997][30046:30048] CHIP:DMG:         {
[1694055309.366026][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055309.366063][30046:30048] CHIP:DMG:             {
[1694055309.366091][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055309.366128][30046:30048] CHIP:DMG:                 {
[1694055309.366160][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055309.366209][30046:30048] CHIP:DMG:                     ClusterId = 0x3e,
[1694055309.366247][30046:30048] CHIP:DMG:                     CommandId = 0x3,
[1694055309.366283][30046:30048] CHIP:DMG:                 },
[1694055309.366326][30046:30048] CHIP:DMG:                 
[1694055309.366360][30046:30048] CHIP:DMG:                 CommandFields =
[1694055309.366394][30046:30048] CHIP:DMG:                 {
[1694055309.366435][30046:30048] CHIP:DMG:                     0x0 = [
[1694055309.366625][30046:30048] CHIP: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
[1694055309.366775][30046:30048] CHIP:DMG:                     ] (492 bytes)
[1694055309.366804][30046:30048] CHIP:DMG:                 },
[1694055309.366834][30046:30048] CHIP:DMG:             },
[1694055309.366876][30046:30048] CHIP:DMG:             
[1694055309.366897][30046:30048] CHIP:DMG:         },
[1694055309.366937][30046:30048] CHIP:DMG:         
[1694055309.366969][30046:30048] CHIP:DMG:     ],
[1694055309.367015][30046:30048] CHIP:DMG:     
[1694055309.367046][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055309.367070][30046:30048] CHIP:DMG: },
[1694055309.367182][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1694055309.367229][30046:30048] CHIP:CTL: Received certificate chain from the device
[1694055309.367261][30046:30048] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest'
[1694055309.367293][30046:30048] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1694055309.367326][30046:30048] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest'
[1694055309.367344][30046:30048] CHIP:CTL: Sending Attestation Request to the device.
[1694055309.367358][30046:30048] CHIP:CTL: Sending Attestation request to 0x7fba4c00cdb0 device
[1694055309.367411][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055309.367436][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055309.367512][30046:30048] CHIP:EM: <<< [E:3661i S:28753 M:35424725] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055309.367544][30046:30048] CHIP:IN: (S) Sending msg 35424725 on secure session with LSID: 28753
[1694055309.368228][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055309.368272][30046:30048] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information
[1694055309.368377][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055309.453601][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055309.457920][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055309.458202][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055309.548042][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055309.548183][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055309.637599][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055309.637880][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055309.638054][30046:30048] CHIP:EM: >>> [E:3661i S:28753 M:262639355] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055309.638108][30046:30048] CHIP:EM: Found matching exchange: 3661i, Delegate: 0x7fba5404b588
[1694055309.638150][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055309.638219][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055309.638249][30046:30048] CHIP:DMG: {
[1694055309.638277][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055309.638296][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055309.638325][30046:30048] CHIP:DMG:     [
[1694055309.638342][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055309.638369][30046:30048] CHIP:DMG:         {
[1694055309.638386][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055309.638425][30046:30048] CHIP:DMG:             {
[1694055309.638451][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055309.638481][30046:30048] CHIP:DMG:                 {
[1694055309.638502][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055309.638522][30046:30048] CHIP:DMG:                     ClusterId = 0x3e,
[1694055309.638542][30046:30048] CHIP:DMG:                     CommandId = 0x1,
[1694055309.638569][30046:30048] CHIP:DMG:                 },
[1694055309.638597][30046:30048] CHIP:DMG:                 
[1694055309.638616][30046:30048] CHIP:DMG:                 CommandFields =
[1694055309.638636][30046:30048] CHIP:DMG:                 {
[1694055309.638656][30046:30048] CHIP:DMG:                     0x0 = [
[1694055309.638814][30046:30048] CHIP:DMG:                             0x15, 0x31, 0x01, 0x1b, 0x02, 0x30, 0x82, 0x02, 0x17, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x82, 0x02, 0x08, 0x30, 0x82, 0x02, 0x04, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x82, 0x01, 0x70, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x82, 0x01, 0x61, 0x04, 0x82, 0x01, 0x5d, 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
[1694055309.638917][30046:30048] CHIP:DMG:                     ] (583 bytes)
[1694055309.638950][30046:30048] CHIP:DMG:                     0x1 = [
[1694055309.639037][30046:30048] CHIP:DMG:                             0x51, 0x68, 0x55, 0xa8, 0x13, 0xe7, 0xc4, 0x4e, 0xdc, 0x9b, 0xc4, 0xa0, 0x29, 0x50, 0x9b, 0x65, 0x26, 0x3a, 0xa1, 0x7e, 0x47, 0x88, 0x94, 0xc0, 0xbf, 0xf2, 0xda, 0xe8, 0x61, 0x4b, 0x28, 0x5b, 0x83, 0xc1, 0xd7, 0x28, 0x60, 0xd5, 0xbc, 0x43, 0x98, 0x64, 0x62, 0x31, 0xfa, 0xa4, 0xa5, 0xd2, 0x7c, 0x7a, 0x45, 0x9a, 0xf0, 0xca, 0x24, 0x91, 0xd2, 0xdf, 0x86, 0xdf, 0xbe, 0x1c, 0xa3, 0xa2,
[1694055309.639080][30046:30048] CHIP:DMG:                     ] (64 bytes)
[1694055309.639113][30046:30048] CHIP:DMG:                 },
[1694055309.639139][30046:30048] CHIP:DMG:             },
[1694055309.639180][30046:30048] CHIP:DMG:             
[1694055309.639203][30046:30048] CHIP:DMG:         },
[1694055309.639245][30046:30048] CHIP:DMG:         
[1694055309.639267][30046:30048] CHIP:DMG:     ],
[1694055309.639311][30046:30048] CHIP:DMG:     
[1694055309.639334][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055309.639358][30046:30048] CHIP:DMG: },
[1694055309.639459][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1694055309.639499][30046:30048] CHIP:CTL: Received Attestation Information from the device
[1694055309.639531][30046:30048] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest'
[1694055309.639555][30046:30048] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 583/583
[1694055309.639590][30046:30048] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1694055309.639618][30046:30048] CHIP:CTL: Performing next commissioning step 'AttestationVerification'
[1694055309.639642][30046:30048] CHIP:CTL: Verifying attestation
[1694055309.671082][30046:30048] CHIP:CR: mbedTLS error: ERROR - Generic error
[1694055309.702299][30046:30048] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device.
[1694055309.702321][30046:30048] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification'
[1694055309.702327][30046:30048] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest'
[1694055309.702338][30046:30048] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest'
[1694055309.702346][30046:30048] CHIP:CTL: Sending CSR request to 0x7fba4c00cdb0 device
[1694055309.702381][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055309.702390][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055309.702425][30046:30048] CHIP:EM: <<< [E:3662i S:28753 M:35424726] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055309.702438][30046:30048] CHIP:IN: (S) Sending msg 35424726 on secure session with LSID: 28753
[1694055309.703140][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055309.703173][30046:30048] CHIP:CTL: Sent CSR request, waiting for the CSR
[1694055309.703213][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055309.769339][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055309.952470][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055309.952642][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055310.041240][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055310.041415][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055310.041567][30046:30048] CHIP:EM: >>> [E:3662i S:28753 M:262639356] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055310.041614][30046:30048] CHIP:EM: Found matching exchange: 3662i, Delegate: 0x7fba5404b198
[1694055310.041654][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055310.041719][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055310.041745][30046:30048] CHIP:DMG: {
[1694055310.041768][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055310.041807][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055310.041859][30046:30048] CHIP:DMG:     [
[1694055310.041890][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055310.041927][30046:30048] CHIP:DMG:         {
[1694055310.041967][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055310.042004][30046:30048] CHIP:DMG:             {
[1694055310.042036][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055310.042073][30046:30048] CHIP:DMG:                 {
[1694055310.042113][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055310.042153][30046:30048] CHIP:DMG:                     ClusterId = 0x3e,
[1694055310.042186][30046:30048] CHIP:DMG:                     CommandId = 0x5,
[1694055310.042219][30046:30048] CHIP:DMG:                 },
[1694055310.042254][30046:30048] CHIP:DMG:                 
[1694055310.042280][30046:30048] CHIP:DMG:                 CommandFields =
[1694055310.042316][30046:30048] CHIP:DMG:                 {
[1694055310.042347][30046:30048] CHIP:DMG:                     0x0 = [
[1694055310.042547][30046:30048] CHIP:DMG:                             0x15, 0x30, 0x01, 0xcd, 0x30, 0x81, 0xca, 0x30, 0x70, 0x02, 0x01, 0x00, 0x30, 0x0e, 0x31, 0x0c, 0x30, 0x0a, 0x06, 0x03, 0x55, 0x04, 0x0a, 0x0c, 0x03, 0x43, 0x53, 0x52, 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, 0x8c, 0xb8, 0xf8, 0xdc, 0xae, 0x36, 0xba, 0x3e, 0x76, 0x50, 0x3e, 0x57, 0x68, 0x0e, 0xba, 0x4e, 0xa4, 0xef, 0xd4, 0x52, 0x48, 0x2f, 0x68, 0xe9, 0x3c, 0xde, 0x4a, 0x9f, 0xae, 0xbc, 0x15, 0x63, 0x11, 0xac, 0x67, 0x5a, 0xa0, 0x51, 0x49, 0x93, 0x18, 0x78, 0x75, 0x82, 0x57, 0x9c, 0x02, 0xc5, 0x49, 0x21, 0xb8, 0x2b, 0x46, 0x68, 0xd5, 0x77, 0x41, 0xa8, 0xbb, 0x69, 0xdc, 0xf0, 0xa8, 0xf8, 0xa0, 0x00, 0x30, 0x0c, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x05, 0x00, 0x03, 0x48, 0x00, 0x30, 0x45, 0x02, 0x21, 0x00, 0x8a, 0x33, 0x28, 0xcd, 0x72, 0x3d, 0x55, 0x6e, 0x8b, 0xc7, 0xa9, 0xd1, 0x9d, 0x77, 0xcf, 0x0e, 0xc1, 0xba, 0x67, 0xdd, 0xc2, 0x44, 0x4b, 0x0d, 0x9f, 0x2e, 0x41, 0x36, 0x0a, 0x23, 0xb4, 0x34, 0x02, 0x20, 0x77, 0x20, 0x72, 0x01, 0x0f, 0xc6, 0x1e, 0x6b, 0x6e, 0x9d, 0x36, 0x59, 0x92, 0xfa, 0xa0, 0x0a, 0xaf, 0x4d, 0x5a, 0x8a, 0xd9, 0x75, 0x71, 0x01, 0xd6, 0x02, 0x67, 0xae, 0x7a, 0x06, 0x18, 0x20, 0x30, 0x02, 0x20, 0x5c, 0xf5, 0xb4, 0x5b, 0x2d, 0x2c, 0x64, 0x8d, 0xbc, 0xd2, 0x2b, 0xd2, 0x5c, 0x4e, 0x54, 0xf2, 0x5f, 0xa3, 0xf4, 0xab, 0x36, 0x04, 0x8b, 0xc0, 0x6a, 0xce, 0xc7, 0x7b, 0xbb, 0x5d, 0x29, 0xd0, 0x18,
[1694055310.042610][30046:30048] CHIP:DMG:                     ] (245 bytes)
[1694055310.042647][30046:30048] CHIP:DMG:                     0x1 = [
[1694055310.042741][30046:30048] CHIP:DMG:                             0x5e, 0xbf, 0x2d, 0x48, 0x9f, 0x1c, 0x89, 0xb0, 0x5e, 0xe4, 0x15, 0xb0, 0x36, 0x70, 0x61, 0xee, 0x62, 0x25, 0xdf, 0x9b, 0xf6, 0x89, 0xb0, 0xe5, 0xb6, 0x00, 0xff, 0x3e, 0x02, 0x8a, 0x71, 0xf9, 0xab, 0x5f, 0x1d, 0x5d, 0x76, 0x20, 0x2b, 0xf6, 0x55, 0xf4, 0xc2, 0x37, 0xdf, 0xea, 0x4f, 0x52, 0xf1, 0x06, 0x4f, 0xb0, 0x1f, 0xe7, 0x58, 0xf1, 0xf2, 0x6b, 0x16, 0x87, 0xd4, 0xbf, 0x7f, 0x40,
[1694055310.042781][30046:30048] CHIP:DMG:                     ] (64 bytes)
[1694055310.042816][30046:30048] CHIP:DMG:                 },
[1694055310.042844][30046:30048] CHIP:DMG:             },
[1694055310.042890][30046:30048] CHIP:DMG:             
[1694055310.042917][30046:30048] CHIP:DMG:         },
[1694055310.042960][30046:30048] CHIP:DMG:         
[1694055310.042987][30046:30048] CHIP:DMG:     ],
[1694055310.043036][30046:30048] CHIP:DMG:     
[1694055310.043064][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055310.043090][30046:30048] CHIP:DMG: },
[1694055310.043215][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1694055310.043256][30046:30048] CHIP:CTL: Received certificate signing request from the device
[1694055310.043293][30046:30048] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest'
[1694055310.043324][30046:30048] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
[1694055310.043361][30046:30048] CHIP:CTL: Performing next commissioning step 'ValidateCSR'
[1694055310.070010][30046:30048] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR'
[1694055310.070056][30046:30048] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
[1694055310.070079][30046:30048] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain'
[1694055310.070090][30046:30048] CHIP:CTL: Getting certificate chain for the device from the issuer
[1694055310.070135][30046:30048] CHIP:CTL: Verifying Certificate Signing Request
[1694055310.080317][30046:30048] CHIP:CTL: Generating NOC
[1694055310.084219][30046:30048] CHIP:CTL: Providing certificate chain to the commissioner
[1694055310.084234][30046:30048] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status src/controller/ExampleOperationalCredentialsIssuer.cpp:396: Success
[1694055310.084245][30046:30048] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain'
[1694055310.084312][30046:30048] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert'
[1694055310.084320][30046:30048] CHIP:CTL: Sending root certificate to the device
[1694055310.084355][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055310.084367][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055310.084407][30046:30048] CHIP:EM: <<< [E:3663i S:28753 M:35424727] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055310.084417][30046:30048] CHIP:IN: (S) Sending msg 35424727 on secure session with LSID: 28753
[1694055310.084562][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055310.084576][30046:30048] CHIP:CTL: Sent root certificate to the device
[1694055310.084716][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055310.173280][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055310.308396][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055310.356014][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055310.356310][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055310.356543][30046:30048] CHIP:EM: >>> [E:3663i S:28753 M:262639357] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055310.356599][30046:30048] CHIP:EM: Found matching exchange: 3663i, Delegate: 0x7fba5404b588
[1694055310.356650][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055310.356727][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055310.356764][30046:30048] CHIP:DMG: {
[1694055310.356792][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055310.356823][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055310.356868][30046:30048] CHIP:DMG:     [
[1694055310.356895][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055310.356934][30046:30048] CHIP:DMG:         {
[1694055310.356965][30046:30048] CHIP:DMG:             CommandStatusIB =
[1694055310.356995][30046:30048] CHIP:DMG:             {
[1694055310.357026][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055310.357056][30046:30048] CHIP:DMG:                 {
[1694055310.357086][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055310.357121][30046:30048] CHIP:DMG:                     ClusterId = 0x3e,
[1694055310.357147][30046:30048] CHIP:DMG:                     CommandId = 0xb,
[1694055310.357169][30046:30048] CHIP:DMG:                 },
[1694055310.357203][30046:30048] CHIP:DMG:                 
[1694055310.357225][30046:30048] CHIP:DMG:                 StatusIB =
[1694055310.357251][30046:30048] CHIP:DMG:                 {
[1694055310.357276][30046:30048] CHIP:DMG:                     status = 0x00 (SUCCESS),
[1694055310.357299][30046:30048] CHIP:DMG:                 },
[1694055310.357325][30046:30048] CHIP:DMG:                 
[1694055310.357346][30046:30048] CHIP:DMG:             },
[1694055310.357388][30046:30048] CHIP:DMG:             
[1694055310.357411][30046:30048] CHIP:DMG:         },
[1694055310.357450][30046:30048] CHIP:DMG:         
[1694055310.357469][30046:30048] CHIP:DMG:     ],
[1694055310.357510][30046:30048] CHIP:DMG:     
[1694055310.357531][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055310.357556][30046:30048] CHIP:DMG: },
[1694055310.357649][30046:30048] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1694055310.357677][30046:30048] CHIP:CTL: Device confirmed that it has received the root certificate
[1694055310.357710][30046:30048] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert'
[1694055310.357736][30046:30048] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1694055310.357768][30046:30048] CHIP:CTL: Performing next commissioning step 'SendNOC'
[1694055310.357837][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055310.357877][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055310.357987][30046:30048] CHIP:EM: <<< [E:3664i S:28753 M:35424728] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055310.358030][30046:30048] CHIP:IN: (S) Sending msg 35424728 on secure session with LSID: 28753
[1694055310.358602][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055310.358641][30046:30048] CHIP:CTL: Sent operational certificate to the device
[1694055310.358705][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055310.444037][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055310.578334][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055310.668398][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055310.805706][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055310.806002][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055310.806186][30046:30048] CHIP:EM: >>> [E:3664i S:28753 M:262639358] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055310.806247][30046:30048] CHIP:EM: Found matching exchange: 3664i, Delegate: 0x7fba5404b198
[1694055310.806312][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055310.806383][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055310.806410][30046:30048] CHIP:DMG: {
[1694055310.806435][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055310.806463][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055310.806502][30046:30048] CHIP:DMG:     [
[1694055310.806519][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055310.806547][30046:30048] CHIP:DMG:         {
[1694055310.806564][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055310.806584][30046:30048] CHIP:DMG:             {
[1694055310.806601][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055310.806621][30046:30048] CHIP:DMG:                 {
[1694055310.806653][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055310.806685][30046:30048] CHIP:DMG:                     ClusterId = 0x3e,
[1694055310.806717][30046:30048] CHIP:DMG:                     CommandId = 0x8,
[1694055310.806746][30046:30048] CHIP:DMG:                 },
[1694055310.806779][30046:30048] CHIP:DMG:                 
[1694055310.806798][30046:30048] CHIP:DMG:                 CommandFields =
[1694055310.806817][30046:30048] CHIP:DMG:                 {
[1694055310.806838][30046:30048] CHIP:DMG:                     0x0 = 0,
[1694055310.806858][30046:30048] CHIP:DMG:                     0x1 = 1,
[1694055310.806879][30046:30048] CHIP:DMG:                 },
[1694055310.806896][30046:30048] CHIP:DMG:             },
[1694055310.806921][30046:30048] CHIP:DMG:             
[1694055310.806950][30046:30048] CHIP:DMG:         },
[1694055310.806995][30046:30048] CHIP:DMG:         
[1694055310.807017][30046:30048] CHIP:DMG:     ],
[1694055310.807061][30046:30048] CHIP:DMG:     
[1694055310.807084][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055310.807107][30046:30048] CHIP:DMG: },
[1694055310.807210][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1694055310.807251][30046:30048] CHIP:CTL: Device returned status 0 on receiving the NOC
[1694055310.807272][30046:30048] CHIP:CTL: Operational credentials provisioned on device 0x7fba4c00cdb0
[1694055310.807297][30046:30048] CHIP:TOO: Secure Pairing Success
[1694055310.807318][30046:30048] CHIP:TOO: CASE establishment successful
[1694055310.807347][30046:30048] CHIP:CTL: Successfully finished commissioning step 'SendNOC'
[1694055310.807373][30046:30048] CHIP:CTL: No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks
[1694055310.807397][30046:30048] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup'
[1694055310.807429][30046:30048] CHIP:CTL: Performing next commissioning step 'ThreadNetworkSetup'
[1694055310.807495][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055310.807548][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055310.807636][30046:30048] CHIP:EM: <<< [E:3665i S:28753 M:35424729] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055310.807675][30046:30048] CHIP:IN: (S) Sending msg 35424729 on secure session with LSID: 28753
[1694055310.808102][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055310.808195][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055310.893363][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055310.895509][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055310.895795][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055310.895975][30046:30048] CHIP:EM: >>> [E:3665i S:28753 M:262639359] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055310.896024][30046:30048] CHIP:EM: Found matching exchange: 3665i, Delegate: 0x7fba5404b588
[1694055310.896081][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055310.896147][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055310.896170][30046:30048] CHIP:DMG: {
[1694055310.896191][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055310.896211][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055310.896253][30046:30048] CHIP:DMG:     [
[1694055310.896278][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055310.896370][30046:30048] CHIP:DMG:         {
[1694055310.896402][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055310.896430][30046:30048] CHIP:DMG:             {
[1694055310.896462][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055310.896491][30046:30048] CHIP:DMG:                 {
[1694055310.896528][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055310.896576][30046:30048] CHIP:DMG:                     ClusterId = 0x31,
[1694055310.896619][30046:30048] CHIP:DMG:                     CommandId = 0x5,
[1694055310.896645][30046:30048] CHIP:DMG:                 },
[1694055310.896666][30046:30048] CHIP:DMG:                 
[1694055310.896702][30046:30048] CHIP:DMG:                 CommandFields =
[1694055310.896739][30046:30048] CHIP:DMG:                 {
[1694055310.896778][30046:30048] CHIP:DMG:                     0x0 = 0,
[1694055310.896820][30046:30048] CHIP:DMG:                     0x2 = 0,
[1694055310.896856][30046:30048] CHIP:DMG:                 },
[1694055310.896889][30046:30048] CHIP:DMG:             },
[1694055310.896939][30046:30048] CHIP:DMG:             
[1694055310.896972][30046:30048] CHIP:DMG:         },
[1694055310.897021][30046:30048] CHIP:DMG:         
[1694055310.897052][30046:30048] CHIP:DMG:     ],
[1694055310.897103][30046:30048] CHIP:DMG:     
[1694055310.897135][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055310.897167][30046:30048] CHIP:DMG: },
[1694055310.897284][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1694055310.898485][30046:30048] CHIP:CTL: Received NetworkConfig response, networkingStatus=0
[1694055310.898533][30046:30048] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkSetup'
[1694055310.898555][30046:30048] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkSetup' -> 'FailsafeBeforeThreadEnable'
[1694055310.898582][30046:30048] CHIP:CTL: Performing next commissioning step 'FailsafeBeforeThreadEnable'
[1694055310.898620][30046:30048] CHIP:CTL: Arming failsafe (76 seconds)
[1694055310.898690][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055310.898779][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055310.898916][30046:30048] CHIP:EM: <<< [E:3666i S:28753 M:35424730] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055310.898960][30046:30048] CHIP:IN: (S) Sending msg 35424730 on secure session with LSID: 28753
[1694055310.899495][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055310.899600][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055310.983338][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055310.985749][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055310.986021][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055310.986195][30046:30048] CHIP:EM: >>> [E:3666i S:28753 M:262639360] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055310.986240][30046:30048] CHIP:EM: Found matching exchange: 3666i, Delegate: 0x7fba5404b198
[1694055310.986283][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055310.986351][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055310.986379][30046:30048] CHIP:DMG: {
[1694055310.986426][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055310.986447][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055310.986487][30046:30048] CHIP:DMG:     [
[1694055310.986518][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055310.986560][30046:30048] CHIP:DMG:         {
[1694055310.986588][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055310.986621][30046:30048] CHIP:DMG:             {
[1694055310.986649][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055310.986681][30046:30048] CHIP:DMG:                 {
[1694055310.986711][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055310.986744][30046:30048] CHIP:DMG:                     ClusterId = 0x30,
[1694055310.986772][30046:30048] CHIP:DMG:                     CommandId = 0x1,
[1694055310.986801][30046:30048] CHIP:DMG:                 },
[1694055310.986838][30046:30048] CHIP:DMG:                 
[1694055310.986864][30046:30048] CHIP:DMG:                 CommandFields =
[1694055310.986897][30046:30048] CHIP:DMG:                 {
[1694055310.986929][30046:30048] CHIP:DMG:                     0x0 = 0,
[1694055310.986962][30046:30048] CHIP:DMG:                     0x1 = "" (0 chars),
[1694055310.986995][30046:30048] CHIP:DMG:                 },
[1694055310.987020][30046:30048] CHIP:DMG:             },
[1694055310.987061][30046:30048] CHIP:DMG:             
[1694055310.987084][30046:30048] CHIP:DMG:         },
[1694055310.987125][30046:30048] CHIP:DMG:         
[1694055310.987147][30046:30048] CHIP:DMG:     ],
[1694055310.987191][30046:30048] CHIP:DMG:     
[1694055310.987214][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055310.987237][30046:30048] CHIP:DMG: },
[1694055310.987337][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1694055310.987380][30046:30048] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1694055310.987410][30046:30048] CHIP:CTL: Successfully finished commissioning step 'FailsafeBeforeThreadEnable'
[1694055310.987435][30046:30048] CHIP:CTL: Commissioning stage next step: 'FailsafeBeforeThreadEnable' -> 'ThreadNetworkEnable'
[1694055310.987469][30046:30048] CHIP:CTL: Performing next commissioning step 'ThreadNetworkEnable'
[1694055310.987559][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055310.987596][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055310.987689][30046:30048] CHIP:EM: <<< [E:3667i S:28753 M:35424731] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055310.987733][30046:30048] CHIP:IN: (S) Sending msg 35424731 on secure session with LSID: 28753
[1694055310.988090][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055310.988195][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055311.073494][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055312.290110][30046:30047] CHIP:DL: Indication received, conn = 0x7fba540481d0
[1694055312.290410][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1694055312.290573][30046:30048] CHIP:EM: >>> [E:3667i S:28753 M:262639361] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055312.290636][30046:30048] CHIP:EM: Found matching exchange: 3667i, Delegate: 0x7fba5404b588
[1694055312.290681][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055312.290754][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055312.290785][30046:30048] CHIP:DMG: {
[1694055312.290817][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055312.290850][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055312.290900][30046:30048] CHIP:DMG:     [
[1694055312.290927][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055312.290971][30046:30048] CHIP:DMG:         {
[1694055312.291001][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055312.291038][30046:30048] CHIP:DMG:             {
[1694055312.291065][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055312.291104][30046:30048] CHIP:DMG:                 {
[1694055312.291140][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055312.291173][30046:30048] CHIP:DMG:                     ClusterId = 0x31,
[1694055312.291206][30046:30048] CHIP:DMG:                     CommandId = 0x7,
[1694055312.291236][30046:30048] CHIP:DMG:                 },
[1694055312.291273][30046:30048] CHIP:DMG:                 
[1694055312.291298][30046:30048] CHIP:DMG:                 CommandFields =
[1694055312.291330][30046:30048] CHIP:DMG:                 {
[1694055312.291365][30046:30048] CHIP:DMG:                     0x0 = 0,
[1694055312.291396][30046:30048] CHIP:DMG:                     0x2 = NULL
[1694055312.291426][30046:30048] CHIP:DMG:                 },
[1694055312.291456][30046:30048] CHIP:DMG:             },
[1694055312.291498][30046:30048] CHIP:DMG:             
[1694055312.291527][30046:30048] CHIP:DMG:         },
[1694055312.291561][30046:30048] CHIP:DMG:         
[1694055312.291581][30046:30048] CHIP:DMG:     ],
[1694055312.291615][30046:30048] CHIP:DMG:     
[1694055312.291637][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055312.291656][30046:30048] CHIP:DMG: },
[1694055312.291748][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1694055312.291786][30046:30048] CHIP:CTL: Received ConnectNetwork response, networkingStatus=0
[1694055312.291813][30046:30048] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkEnable'
[1694055312.291836][30046:30048] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkEnable' -> 'FindOperational'
[1694055312.291862][30046:30048] CHIP:CTL: Performing next commissioning step 'FindOperational'
[1694055312.291882][30046:30048] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001]
[1694055312.291904][30046:30048] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1694055312.291941][30046:30048] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1694055312.291970][30046:30048] CHIP:DIS: Resolving E6F06EAE27CA3AAD:0000000000000001 ...
[1694055312.293632][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055312.492172][30046:30048] CHIP:DIS: Checking node lookup status after 200 ms
[1694055314.594185][30046:30048] CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:154: CHIP Error 0x00000032: Timeout
[1694055314.746478][30046:30048] CHIP:DL: Avahi resolve found
[1694055314.746560][30046:30048] CHIP:DIS: Node ID resolved for E6F06EAE27CA3AAD:0000000000000001
[1694055314.746593][30046:30048] CHIP:DIS:     Hostname: B2900DF27857DC1A
[1694055314.746621][30046:30048] CHIP:DIS:     IP Address #1: fd11:22::869f:b360:f73c:e91a
[1694055314.746641][30046:30048] CHIP:DIS:     Port: 5540
[1694055314.746660][30046:30048] CHIP:DIS:     Mrp Interval idle: 1000 ms
[1694055314.746678][30046:30048] CHIP:DIS:     Mrp Interval active: 1000 ms
[1694055314.746701][30046:30048] CHIP:DIS:     TCP Supported: 0
[1694055314.747082][30046:30048] CHIP:DIS: Lookup clearing interface for non LL address
[1694055314.747249][30046:30048] CHIP:DIS: UDP:[fd11:22::869f:b360:f73c:e91a%wlp5s0]:5540: new best score: 4
[1694055314.747277][30046:30048] CHIP:DIS: Checking node lookup status after 2455 ms
[1694055314.747327][30046:30048] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd11:22::869f:b360:f73c:e91a]:5540 while in state 2
[1694055314.747352][30046:30048] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
[1694055314.747430][30046:30048] CHIP:IN: SecureSession[0x7fba4c020bb0]: Allocated Type:2 LSID:28754
[1694055314.747472][30046:30048] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
[1694055314.762355][30046:30048] CHIP:EM: <<< [E:3668i S:0 M:112192128] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1694055314.762475][30046:30048] CHIP:IN: (U) Sending msg 112192128 to IP address 'UDP:[fd11:22::869f:b360:f73c:e91a]:5540'
[1694055314.762777][30046:30048] CHIP:SC: Sent Sigma1 msg
[1694055314.762820][30046:30048] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
[1694055314.840963][30046:30048] CHIP:EM: >>> [E:3668i S:0 M:199762178 (Ack:112192128)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1694055314.841007][30046:30048] CHIP:EM: Found matching exchange: 3668i, Delegate: 0x7fba4c020928
[1694055314.841038][30046:30048] CHIP:EM: Rxd Ack; Removing MessageCounter:112192128 from Retrans Table on exchange 3668i
[1694055314.853039][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1694055315.115067][30046:30048] CHIP:EM: >>> [E:3668i S:0 M:199762179 (Ack:112192128)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1694055315.115094][30046:30048] CHIP:EM: Found matching exchange: 3668i, Delegate: 0x7fba4c020928
[1694055315.115105][30046:30048] CHIP:EM: CHIP MessageCounter:112192128 not in RetransTable on exchange 3668i
[1694055315.115125][30046:30048] CHIP:SC: Received Sigma2 msg
[1694055315.115140][30046:30048] CHIP:SC: Peer assigned session session ID 6458
[1694055315.164104][30046:30048] CHIP:SC: Found MRP parameters in the message
[1694055315.164125][30046:30048] CHIP:SC: Sending Sigma3
[1694055315.168782][30046:30048] CHIP:EM: <<< [E:3668i S:0 M:112192129 (Ack:199762179)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1694055315.168838][30046:30048] CHIP:IN: (U) Sending msg 112192129 to IP address 'UDP:[fd11:22::869f:b360:f73c:e91a%wlp5s0]:5540'
[1694055315.168921][30046:30048] CHIP:SC: Sent Sigma3 msg
[1694055315.255509][30046:30048] CHIP:EM: >>> [E:3668i S:0 M:199762180 (Ack:112192129)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1694055315.255559][30046:30048] CHIP:EM: Found matching exchange: 3668i, Delegate: 0x7fba4c020928
[1694055315.255601][30046:30048] CHIP:EM: Rxd Ack; Removing MessageCounter:112192129 from Retrans Table on exchange 3668i
[1694055315.666590][30046:30048] CHIP:EM: >>> [E:3668i S:0 M:199762181 (Ack:112192129)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1694055315.666648][30046:30048] CHIP:EM: Found matching exchange: 3668i, Delegate: 0x7fba4c020928
[1694055315.666680][30046:30048] CHIP:EM: CHIP MessageCounter:112192129 not in RetransTable on exchange 3668i
[1694055315.666745][30046:30048] CHIP:SC: Success status report received. Session was established
[1694055315.669230][30046:30048] CHIP:SC: SecureSession[0x7fba4c020bb0]: Moving from state 'kEstablishing' --> 'kActive'
[1694055315.669264][30046:30048] CHIP:IN: SecureSession[0x7fba4c020bb0]: Activated - Type:2 LSID:28754
[1694055315.669294][30046:30048] CHIP:IN: New secure session activated for device <0000000000000001, 1>, LSID:28754 PSID:6458!
[1694055315.669331][30046:30048] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5
[1694055315.669401][30046:30048] CHIP:CTL: Successfully finished commissioning step 'FindOperational'
[1694055315.669425][30046:30048] CHIP:CTL: Commissioning stage next step: 'FindOperational' -> 'SendComplete'
[1694055315.669465][30046:30048] CHIP:CTL: Performing next commissioning step 'SendComplete'
[1694055315.669533][30046:30048] CHIP:DMG: ICR moving to [AddingComm]
[1694055315.669562][30046:30048] CHIP:DMG: ICR moving to [AddedComma]
[1694055315.669690][30046:30048] CHIP:EM: <<< [E:3669i S:28754 M:196322203] (S) Msg TX to 1:0000000000000001 [3AAD] --- Type 0001:08 (IM:InvokeCommandRequest)
[1694055315.669742][30046:30048] CHIP:IN: (S) Sending msg 196322203 on secure session with LSID: 28754
[1694055315.669899][30046:30048] CHIP:DMG: ICR moving to [CommandSen]
[1694055315.669980][30046:30048] CHIP:EM: <<< [E:3668i S:0 M:112192130 (Ack:199762181)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1694055315.670088][30046:30048] CHIP:IN: (U) Sending msg 112192130 to IP address 'UDP:[fd11:22::869f:b360:f73c:e91a%wlp5s0]:5540'
[1694055315.670180][30046:30048] CHIP:EM: Flushed pending ack for MessageCounter:199762181 on exchange 3668i
[1694055316.076829][30046:30048] CHIP:EM: >>> [E:3669i S:28754 M:42402055 (Ack:196322203)] (S) Msg RX from 1:0000000000000001 [3AAD] --- Type 0001:09 (IM:InvokeCommandResponse)
[1694055316.076901][30046:30048] CHIP:EM: Found matching exchange: 3669i, Delegate: 0x7fba5404b198
[1694055316.076959][30046:30048] CHIP:EM: Rxd Ack; Removing MessageCounter:196322203 from Retrans Table on exchange 3669i
[1694055316.077012][30046:30048] CHIP:DMG: ICR moving to [ResponseRe]
[1694055316.077080][30046:30048] CHIP:DMG: InvokeResponseMessage =
[1694055316.077116][30046:30048] CHIP:DMG: {
[1694055316.077146][30046:30048] CHIP:DMG:     suppressResponse = false,
[1694055316.077167][30046:30048] CHIP:DMG:     InvokeResponseIBs =
[1694055316.077208][30046:30048] CHIP:DMG:     [
[1694055316.077241][30046:30048] CHIP:DMG:         InvokeResponseIB =
[1694055316.077285][30046:30048] CHIP:DMG:         {
[1694055316.077316][30046:30048] CHIP:DMG:             CommandDataIB =
[1694055316.077351][30046:30048] CHIP:DMG:             {
[1694055316.077384][30046:30048] CHIP:DMG:                 CommandPathIB =
[1694055316.077417][30046:30048] CHIP:DMG:                 {
[1694055316.077456][30046:30048] CHIP:DMG:                     EndpointId = 0x0,
[1694055316.077495][30046:30048] CHIP:DMG:                     ClusterId = 0x30,
[1694055316.077543][30046:30048] CHIP:DMG:                     CommandId = 0x5,
[1694055316.077579][30046:30048] CHIP:DMG:                 },
[1694055316.077641][30046:30048] CHIP:DMG:                 
[1694055316.077677][30046:30048] CHIP:DMG:                 CommandFields =
[1694055316.077715][30046:30048] CHIP:DMG:                 {
[1694055316.077756][30046:30048] CHIP:DMG:                     0x0 = 0,
[1694055316.077797][30046:30048] CHIP:DMG:                     0x1 = "" (0 chars),
[1694055316.077837][30046:30048] CHIP:DMG:                 },
[1694055316.077873][30046:30048] CHIP:DMG:             },
[1694055316.077916][30046:30048] CHIP:DMG:             
[1694055316.077947][30046:30048] CHIP:DMG:         },
[1694055316.077988][30046:30048] CHIP:DMG:         
[1694055316.078012][30046:30048] CHIP:DMG:     ],
[1694055316.078059][30046:30048] CHIP:DMG:     
[1694055316.078093][30046:30048] CHIP:DMG:     InteractionModelRevision = 1
[1694055316.078122][30046:30048] CHIP:DMG: },
[1694055316.078252][30046:30048] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
[1694055316.078319][30046:30048] CHIP:CTL: Received CommissioningComplete response, errorCode=0
[1694055316.078376][30046:30048] CHIP:CTL: Successfully finished commissioning step 'SendComplete'
[1694055316.078408][30046:30048] CHIP:CTL: Commissioning stage next step: 'SendComplete' -> 'Cleanup'
[1694055316.078456][30046:30048] CHIP:CTL: Performing next commissioning step 'Cleanup'
[1694055316.078490][30046:30048] CHIP:DIS: Closing all BLE connections
[1694055316.078525][30046:30048] CHIP:IN: Clearing BLE pending packets.
[1694055316.079041][30046:30048] CHIP:BLE: Auto-closing end point's BLE connection.
[1694055316.079087][30046:30048] CHIP:DL: Closing BLE GATT connection (con 0x7fba540481d0)
[1694055316.079213][30046:30047] CHIP:DL: BluezDisconnect peer=EE:05:FD:CE:F6:42
[1694055316.121599][30046:30048] CHIP:IN: SecureSession[0x7fba4c010d00]: MarkForEviction Type:1 LSID:28753
[1694055316.121655][30046:30048] CHIP:SC: SecureSession[0x7fba4c010d00]: Moving from state 'kActive' --> 'kPendingEviction'
[1694055316.121705][30046:30048] CHIP:IN: SecureSession[0x7fba4c010d00]: Released - Type:1 LSID:28753
[1694055316.121749][30046:30048] CHIP:CTL: Successfully finished commissioning step 'Cleanup'
[1694055316.121782][30046:30048] CHIP:TOO: Device commissioning completed with success
[1694055316.121918][30046:30048] CHIP:DMG: ICR moving to [AwaitingDe]
[1694055316.122026][30046:30048] CHIP:EM: <<< [E:3669i S:28754 M:196322204 (Ack:42402055)] (S) Msg TX to 1:0000000000000001 [3AAD] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1694055316.122097][30046:30048] CHIP:IN: (S) Sending msg 196322204 on secure session with LSID: 28754
[1694055316.122290][30046:30048] CHIP:EM: Flushed pending ack for MessageCounter:42402055 on exchange 3669i
[1694055316.122347][30046:30048] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1694055316.122387][30046:30048] CHIP:BLE: no endpoint for unsub complete
[1694055316.122972][30046:30046] CHIP:CTL: Shutting down the commissioner
[1694055316.123025][30046:30046] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1694055316.123059][30046:30046] CHIP:CTL: Shutting down the controller
[1694055316.123088][30046:30046] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1694055316.123111][30046:30046] CHIP:IN: SecureSession[0x7fba4c020bb0]: MarkForEviction Type:2 LSID:28754
[1694055316.123141][30046:30046] CHIP:SC: SecureSession[0x7fba4c020bb0]: Moving from state 'kActive' --> 'kPendingEviction'
[1694055316.123165][30046:30046] CHIP:IN: SecureSession[0x7fba4c020bb0]: Released - Type:2 LSID:28754
[1694055316.123201][30046:30046] CHIP:FP: Forgetting fabric 0x1
[1694055316.123239][30046:30046] CHIP:TS: Pending Last Known Good Time: 2023-07-11T07:53:58
[1694055316.123497][30046:30046] CHIP:TS: Previous Last Known Good Time: 2023-07-11T07:53:58
[1694055316.123536][30046:30046] CHIP:TS: Reverted Last Known Good Time to previous value
[1694055316.123582][30046:30046] CHIP:CTL: Shutting down the commissioner
[1694055316.123609][30046:30046] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1694055316.123635][30046:30046] CHIP:CTL: Shutting down the controller
[1694055316.123658][30046:30046] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1694055316.124061][30046:30047] CHIP:DL: Bluez disconnected
[1694055316.124107][30046:30047] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1694055316.125394][30046:30046] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1694055316.125513][30046:30046] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1694055316.125581][30046:30046] CHIP:FP: Shutting down FabricTable
[1694055316.125613][30046:30046] CHIP:TS: Pending Last Known Good Time: 2023-07-11T07:53:58
[1694055316.125811][30046:30046] CHIP:TS: Previous Last Known Good Time: 2023-07-11T07:53:58
[1694055316.125834][30046:30046] CHIP:TS: Reverted Last Known Good Time to previous value
[1694055316.126108][30046:30046] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-qwZs97)
[1694055316.126728][30046:30046] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1694055316.126786][30046:30046] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1694055316.126815][30046:30046] CHIP:DL: Inet Layer shutdown
[1694055316.126837][30046:30046] CHIP:DL: BLE shutdown
[1694055316.128501][30046:30046] CHIP:DL: System Layer shutdown

[AHaug]

Hi,

Glad to hear that you feel you're progressing! I see that you've had some success here, but just a few questions from so I am on the same page as you.

1. Were you able to flash a Bluetooth sample on the the E73-2G4M08S1C module, for instance the peripheral_uart sample? Where you able to connect with the nRF Connect application for either Android or iOS?
2. Have you implemented all of the changes since my previous reply on a 52840DK, which the images you've posted suggest, or is it on the E73 module?
3. I will see if I find some more information regarding CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC. I see that in the original case they were using NCS v1.7.0, which is 2 years old, so this feature request may have been implemented in newer NCS versions. Based on what you describe, it looks like it may still be required. I will investigate the status on this request.

DoubleAmaing said:

Was it successful?

The commissioning of the device looks successful based on initial looks at the logs. Are you able to communicate with the node using CHIP tool? Can you see the device when you list all nodes in the network?

Kind regards,
Andreas

[DoubleAmaing]

Hi,

thank you for your help.

At present, my tests are all performed on E73-2G4M08S1C (I don't have nRF52840DK).

The schematic diagram is very simple: we use 3.3V to supply power to E73-2G4M08S1C, and lead out Reset, GND, SWDIO, SWCLK for flash programs; in addition, Reset (p0.18) pin connects a capacitor (104) to GND; XL1, XL2 are not connected to 32K crystal oscillator, XC1, XC2 are connected to 32M crystal oscillator;

Were you able to flash a Bluetooth sample on the the E73-2G4M08S1C module, 
for instance the peripheral_uart sample? 
Where you able to connect with the nRF Connect application for either Android or iOS?

Reply：Yes, I can download bluetooth program on E73-2G4M08S1C. After I added CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC, I can connect to E73-2G4M08S1C using nRF connect for Mobile.

nRF connect for mobile download link: https://www.nordicsemi.com/Products/Development-tools/nrf-connect-for-mobile

Have you implemented all of the changes since my previous reply on a 52840DK, 
which the images you've posted suggest, or is it on the E73 module?

Reply:

I am using the matter example (Light_Blub), I just added: CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC=y

CONFIG_SOC_ENABLE_LFXO=n

No other modifications are made.

I will see if I find some more information regarding CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC.
I see that in the original case they were using NCS v1.7.0, 
which is 2 years old, so this feature request may have been implemented in newer NCS versions. 
Based on what you describe, it looks like it may still be required. 
I will investigate the status on this request.

Reply：

CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC, does this configuration enable the internal crystal oscillator?

My XL1 and XL2 are not connected to a crystal oscillator

The commissioning of the device looks successful based on initial looks at the logs. 
Are you able to communicate with the node using CHIP tool? 
Can you see the device when you list all nodes in the network?

Reply:

Yes, i can see him and i use command ./chip-tool-debug onoff toggle 1 1 to control it;

I measure the output of the IO with a meter, and I can see it flipping 0V or 3.3V;

---------------------------

Sorry I have so many questions, thanks for helping me out. I have another question to attach to you, please help me:

I use matter's example (Light_Blub), the board can't run when power on, because I don't see any information printed through the J-Link console. However, when I send the "Reset Board" command through the Vs Code (CONNECTED DEVICES) interface, I can see the terminal print a lot of information, and I know the board is working. I have connected a 104 capacitor to GND on the P0.18/Reset pin of the board, what else should I do? My schematic is as stated above, and it's pretty simple, so I'm not sure if it's my hardware reset that isn't working perfectly enough.