chip-tool PASESession timed out, fails to commission device on Mac

On the Mac With ToT (92fc1fb86625250bc59b47b2dae1bd45e65b8163) chip-tool "PASESession timed out"
-------- Chip tool log ---------------------
[1624394756638] [0x672671] CHIP: [DL] _Init
[1624394756638] [0x672671] CHIP: [IN] TransportMgr initialized
[1624394756638] [0x672671] CHIP: [DIS] Init admin pairing table with server storage
[1624394756638] [0x672671] CHIP: [IN] local node id is 0x000000000001B669
[1624394756638] [0x672671] CHIP: [ZCL] Using ZAP configuration...
[1624394756638] [0x672671] CHIP: [ZCL] deactivate report event
[1624394756638] [0x672671] CHIP: [CTL] Getting operational keys
[1624394756639] [0x672671] CHIP: [CTL] Generating operational certificate for the controller
[1624394756639] [0x672671] CHIP: [CTL] Getting root certificate for the controller from the issuer
[1624394756640] [0x672671] CHIP: [CTL] Generating credentials
[1624394756640] [0x672671] CHIP: [CTL] Loaded credentials successfully
[1624394756640] [0x672671] CHIP: [BLE] NewConnection
[1624394756642] [0x672671] CHIP: [SC] Assigned local session key ID 0
[1624394756642] [0x672671] CHIP: [IN] Message appended to BLE send queue
[1624394756642] [0x672671] CHIP: [SC] Sent PBKDF param request
[1624394756698] [0x672676] CHIP: [BLE] CBManagerState: ON
[1624394759904] [0x672675] CHIP: [BLE] Connecting to device with discriminator: 3840
[1624394762975] [0x672675] CHIP: [IN] BleConnectionComplete: endPoint 0x10c0f7428
[1624394762975] [0x672675] CHIP: [BLE] Ble endpoint pool FULL
[1624394762975] [0x672675] CHIP: [IN] Clearing BLE pending packets.
[1624394762975] [0x672675] CHIP: [IN] BleConnection Error: Ble Error 6002 (0x00001772): No more BLE endpoints
[1624394763829] [0x672675] CHIP: [BLE] subscribe complete, ep = 0x10c0f7428
[1624394763877] [0x672675] CHIP: [BLE] peripheral chose BTP version 3; central expected between 2 and 3
[1624394763877] [0x672675] CHIP: [BLE] using BTP fragment sizes rx 20 / tx 128.
[1624394763877] [0x672675] CHIP: [BLE] local and remote recv window size = 3
[1624394763877] [0x672675] CHIP: [IN] BLE EndPoint 0x10c0f7428 Connection Complete
[1624394786645] [0x672675] CHIP: [TOO] Pairing Failure: CHIP Error 4050 (0x00000FD2): Timeout
[1624394786645] [0x672675] CHIP: [SC] PASESession timed out while waiting for a response from the peer. Expected message type was 33
[1624394786645] [0x672675] CHIP: [TOO] Secure Pairing Failed
[1624394786645] [0x672671] CHIP: [TOO] Run command failure: CHIP Error 4172 (0x0000104C): Internal error
[1624394786646] [0x672675] CHIP: [TOO] Pairing Failure: CHIP Error 4050 (0x00000FD2): Timeout
[1624394786646] [0x672671] CHIP: [CTL] Shutting down the commissioner
[1624394786646] [0x672671] CHIP: [CTL] Shutting down the controller
[1624394786646] [0x672671] CHIP: [DL] Inet Layer shutdown
[1624394786646] [0x672671] CHIP: [DL] BLE layer shutdown
[1624394786646] [0x672671] CHIP: [IN] Clearing BLE pending packets.
[1624394786646] [0x672671] CHIP: [BLE] Auto-closing end point's BLE connection.
[1624394786646] [0x672671] CHIP: [DL] System Layer shutdown
chaitanyajandhyala@MacBook-Pro chip-tool %

What does the device side log look like?
That said, this bit:
[1624394762975] [0x672675] CHIP: [BLE] Ble endpoint pool FULL
[1624394762975] [0x672675] CHIP: [IN] Clearing BLE pending packets.
[1624394762975] [0x672675] CHIP: [IN] BleConnection Error: Ble Error 6002 (0x00001772): No more BLE endpoints

might be relevant.  If this is reproducible reliably, please check whether https://github.com/project-chip/connectedhomeip/pull/7806 fixes things?

#7806 fixes the BLE endpoint Full issue and moves fwd with other parts of provisioning flow. but EnableNetwork command seem to fail
[1624408165247] [0x6b003e] CHIP: [DL] _Init
[1624408165247] [0x6b003e] CHIP: [IN] TransportMgr initialized
[1624408165247] [0x6b003e] CHIP: [DIS] Init admin pairing table with server storage
[1624408165248] [0x6b003e] CHIP: [IN] Loading certs from KVS
[1624408165248] [0x6b003e] CHIP: [IN] local node id is 0x000000000001B669
[1624408165248] [0x6b003e] CHIP: [ZCL] Using ZAP configuration...
[1624408165248] [0x6b003e] CHIP: [ZCL] deactivate report event
[1624408165248] [0x6b003e] CHIP: [CTL] Getting operational keys
[1624408165248] [0x6b003e] CHIP: [CTL] Generating credentials
[1624408165248] [0x6b003e] CHIP: [CTL] Loaded credentials successfully
[1624408165248] [0x6b003e] CHIP: [BLE] NewConnection
[1624408165249] [0x6b003e] CHIP: [SC] Assigned local session key ID 1
[1624408165249] [0x6b003e] CHIP: [IN] Message appended to BLE send queue
[1624408165249] [0x6b003e] CHIP: [SC] Sent PBKDF param request
[1624408165303] [0x6b0041] CHIP: [BLE] CBManagerState: ON
[1624408179177] [0x6b00dd] CHIP: [BLE] Connecting to device with discriminator: 3840
[1624408182229] [0x6b00dd] CHIP: [IN] BleConnectionComplete: endPoint 0x10cd180c8
[1624408183083] [0x6b00dd] CHIP: [BLE] subscribe complete, ep = 0x10cd180c8
[1624408183131] [0x6b0044] CHIP: [BLE] peripheral chose BTP version 3; central expected between 2 and 3
[1624408183131] [0x6b0044] CHIP: [BLE] using BTP fragment sizes rx 20 / tx 128.
[1624408183131] [0x6b0044] CHIP: [BLE] local and remote recv window size = 3
[1624408183131] [0x6b0044] CHIP: [IN] BLE EndPoint 0x10cd180c8 Connection Complete
[1624408183759] [0x6b00dd] CHIP: [EM] Received message of type 33 and protocolId 0 on exchange 44249
[1624408183759] [0x6b00dd] CHIP: [SC] Received PBKDF param response
[1624408183762] [0x6b00dd] CHIP: [SC] Sent spake2p msg1
[1624408184660] [0x6b00dd] CHIP: [EM] Received message of type 35 and protocolId 0 on exchange 44249
[1624408184660] [0x6b00dd] CHIP: [SC] Received spake2p msg2
[1624408184660] [0x6b00dd] CHIP: [SC] Peer assigned session key ID 0
[1624408184660] [0x6b00dd] CHIP: [SC] Sent spake2p msg3
[1624408184660] [0x6b00dd] CHIP: [IN] New pairing for device 0x0000000000bc5c01, key 0!!
[1624408184660] [0x6b00dd] CHIP: [CTL] Remote device completed SPAKE2+ handshake
[1624408184660] [0x6b00dd] CHIP: [CTL] Sending root certificate to the device
[1624408184660] [0x6b00dd] CHIP: [DMG] ICR moving to [Initialize]
[1624408184660] [0x6b00dd] CHIP: [DMG] ICR moving to [AddCommand]
[1624408184661] [0x6b00dd] CHIP: [IN] Secure message was encrypted: Msg ID 0
[1624408184661] [0x6b00dd] CHIP: [IN] Encrypted message 0x70000e6dbc60 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44250.
[1624408184661] [0x6b00dd] CHIP: [IN] Sending msg 0x70000e6dbc60 to 0x0000000000BC5C01 at utc time: 552368815 msec
[1624408184661] [0x6b00dd] CHIP: [IN] Sending secure msg on generic transport
[1624408184661] [0x6b00dd] CHIP: [IN] Secure msg send status No Error
[1624408184661] [0x6b00dd] CHIP: [DMG] ICR moving to [   Sending]
[1624408184661] [0x6b00dd] CHIP: [CTL] Sent root certificate to the device
[1624408185785] [0x6b00dd] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 1
[1624408185785] [0x6b00dd] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44250
[1624408185785] [0x6b00dd] CHIP: [DMG] InvokeCommand =
[1624408185785] [0x6b00dd] CHIP: [DMG] {
[1624408185785] [0x6b00dd] CHIP: [DMG] 	CommandList =
[1624408185785] [0x6b00dd] CHIP: [DMG] 	[
[1624408185785] [0x6b00dd] CHIP: [DMG] 		CommandDataElement =
[1624408185785] [0x6b00dd] CHIP: [DMG] 		{
[1624408185785] [0x6b00dd] CHIP: [DMG] 			CommandPath =
[1624408185785] [0x6b00dd] CHIP: [DMG] 			{
[1624408185785] [0x6b00dd] CHIP: [DMG] 				EndpointId = 0x0,
[1624408185785] [0x6b00dd] CHIP: [DMG] 				ClusterId = 0x3e,
[1624408185785] [0x6b00dd] CHIP: [DMG] 				CommandId = 0xa1,
[1624408185785] [0x6b00dd] CHIP: [DMG] 			},
[1624408185785] [0x6b00dd] CHIP: [DMG]
[1624408185785] [0x6b00dd] CHIP: [DMG] 			StatusElement =
[1624408185785] [0x6b00dd] CHIP: [DMG] 			{
[1624408185785] [0x6b00dd] CHIP: [DMG] 				GeneralCode = 0x0,
[1624408185785] [0x6b00dd] CHIP: [DMG] 				ProtocolId = 0x5,
[1624408185785] [0x6b00dd] CHIP: [DMG] 				protocolCode = 0x0,
[1624408185785] [0x6b00dd] CHIP: [DMG] 			},
[1624408185785] [0x6b00dd] CHIP: [DMG]
[1624408185785] [0x6b00dd] CHIP: [DMG] 		},
[1624408185785] [0x6b00dd] CHIP: [DMG]
[1624408185785] [0x6b00dd] CHIP: [DMG] 	],
[1624408185785] [0x6b00dd] CHIP: [DMG]
[1624408185785] [0x6b00dd] CHIP: [DMG] }
[1624408185785] [0x6b00dd] CHIP: [ZCL] DefaultResponse:
[1624408185785] [0x6b00dd] CHIP: [ZCL]   Transaction: 0x10cd18cf8
[1624408185785] [0x6b00dd] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624408185785] [0x6b00dd] CHIP: [CTL] Device confirmed that it has received the root certificate
[1624408185785] [0x6b00dd] CHIP: [CTL] Sending OpCSR request to 0x7ffee308ad88 device
[1624408185785] [0x6b00dd] CHIP: [DMG] ICR moving to [Initialize]
[1624408185785] [0x6b00dd] CHIP: [DMG] ICR moving to [AddCommand]
[1624408185785] [0x6b00dd] CHIP: [IN] Secure message was encrypted: Msg ID 1
[1624408185785] [0x6b00dd] CHIP: [IN] Encrypted message 0x70000e6db8c0 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44251.
[1624408185785] [0x6b00dd] CHIP: [IN] Sending msg 0x70000e6db8c0 to 0x0000000000BC5C01 at utc time: 552369939 msec
[1624408185785] [0x6b00dd] CHIP: [IN] Sending secure msg on generic transport
[1624408185785] [0x6b00dd] CHIP: [IN] Secure msg send status No Error
[1624408185785] [0x6b00dd] CHIP: [DMG] ICR moving to [   Sending]
[1624408185785] [0x6b00dd] CHIP: [CTL] Sent OpCSR request, waiting for the CSR
[1624408185785] [0x6b00dd] CHIP: [DMG] ICR moving to [Uninitiali]
[1624408188260] [0x6b0044] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 1
[1624408188260] [0x6b0044] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44251
[1624408188260] [0x6b0044] CHIP: [DMG] InvokeCommand =
[1624408188260] [0x6b0044] CHIP: [DMG] {
[1624408188260] [0x6b0044] CHIP: [DMG] 	CommandList =
[1624408188260] [0x6b0044] CHIP: [DMG] 	[
[1624408188260] [0x6b0044] CHIP: [DMG] 		CommandDataElement =
[1624408188260] [0x6b0044] CHIP: [DMG] 		{
[1624408188260] [0x6b0044] CHIP: [DMG] 			CommandPath =
[1624408188260] [0x6b0044] CHIP: [DMG] 			{
[1624408188260] [0x6b0044] CHIP: [DMG] 				EndpointId = 0x0,
[1624408188260] [0x6b0044] CHIP: [DMG] 				ClusterId = 0x3e,
[1624408188260] [0x6b0044] CHIP: [DMG] 				CommandId = 0x5,
[1624408188260] [0x6b0044] CHIP: [DMG] 			},
[1624408188260] [0x6b0044] CHIP: [DMG]
[1624408188260] [0x6b0044] CHIP: [DMG] 			CommandData =
[1624408188260] [0x6b0044] CHIP: [DMG] 			{
[1624408188260] [0x6b0044] CHIP: [DMG] 				0x0 = [
[1624408188260] [0x6b0044] CHIP: [DMG] 					0x30, 0x81, 0xc7, 0x30, 0x70, 0x2, 0x1, 0x0, 0x30, 0xe, 0x31, 0xc, 0x30, 0xa, 0x6, 0x3, 0x55, 0x4, 0xa, 0xc, 0x3, 0x43, 0x53, 0x52, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6,
[1624408188260] [0x6b0044] CHIP: [DMG] 			]
[1624408188260] [0x6b0044] CHIP: [DMG] 				0x1 = [
[1624408188260] [0x6b0044] CHIP: [DMG] 					0xf2, 0x95, 0x41, 0x1, 0x6b, 0x42, 0x8, 0x4d, 0x88, 0xeb, 0x59, 0xbc, 0xf4, 0x8d, 0xbf, 0x1d, 0xd, 0x23, 0xe6, 0x90, 0xdb, 0x7a, 0x9b, 0xe6, 0x38, 0xe6, 0x32, 0xaf, 0x5a, 0x9, 0x10, 0xf2,
[1624408188260] [0x6b0044] CHIP: [DMG] 			]
[1624408188260] [0x6b0044] CHIP: [DMG] 				0x2 = [
[1624408188260] [0x6b0044] CHIP: [DMG]
[1624408188260] [0x6b0044] CHIP: [DMG] 			]
[1624408188260] [0x6b0044] CHIP: [DMG] 				0x3 = [
[1624408188260] [0x6b0044] CHIP: [DMG]
[1624408188260] [0x6b0044] CHIP: [DMG] 			]
[1624408188260] [0x6b0044] CHIP: [DMG] 				0x4 = [
[1624408188260] [0x6b0044] CHIP: [DMG]
[1624408188260] [0x6b0044] CHIP: [DMG] 			]
[1624408188260] [0x6b0044] CHIP: [DMG] 				0x5 = [
[1624408188260] [0x6b0044] CHIP: [DMG]
[1624408188260] [0x6b0044] CHIP: [DMG] 			]
[1624408188260] [0x6b0044] CHIP: [DMG] 			},
[1624408188260] [0x6b0044] CHIP: [DMG] 		},
[1624408188260] [0x6b0044] CHIP: [DMG]
[1624408188260] [0x6b0044] CHIP: [DMG] 	],
[1624408188260] [0x6b0044] CHIP: [DMG]
[1624408188260] [0x6b0044] CHIP: [DMG] }
[1624408188260] [0x6b0044] CHIP: [ZCL] Received Cluster Command: Cluster=3e Command=5 Endpoint=0
[1624408188260] [0x6b0044] CHIP: [ZCL] OpCSRResponse:
[1624408188260] [0x6b0044] CHIP: [ZCL]   CSR: 202
[1624408188260] [0x6b0044] CHIP: [ZCL]   CSRNonce: 32
[1624408188260] [0x6b0044] CHIP: [ZCL]   VendorReserved1: 0
[1624408188260] [0x6b0044] CHIP: [ZCL]   VendorReserved2: 0
[1624408188260] [0x6b0044] CHIP: [ZCL]   VendorReserved3: 0
[1624408188260] [0x6b0044] CHIP: [ZCL]   Signature: 0
[1624408188260] [0x6b0044] CHIP: [CTL] Received certificate signing request from the device
[1624408188260] [0x6b0044] CHIP: [CTL] Generating operational certificate for device<PHONE_NUMBER>BC5C01
[1624408188266] [0x6b0044] CHIP: [CTL] Getting intermediate CA certificate from the issuer
[1624408188266] [0x6b0044] CHIP: [CTL] GetIntermediateCACertificate returned 4190
[1624408188266] [0x6b0044] CHIP: [CTL] Intermediate CA is not needed
[1624408188266] [0x6b0044] CHIP: [CTL] Sending operational certificate to the device. Op Cert Len 246
[1624408188266] [0x6b0044] CHIP: [DMG] ICR moving to [Initialize]
[1624408188266] [0x6b0044] CHIP: [DMG] ICR moving to [AddCommand]
[1624408188266] [0x6b0044] CHIP: [IN] Secure message was encrypted: Msg ID 2
[1624408188266] [0x6b0044] CHIP: [IN] Encrypted message 0x70000e7e12c0 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44252.
[1624408188266] [0x6b0044] CHIP: [IN] Sending msg 0x70000e7e12c0 to 0x0000000000BC5C01 at utc time: 552372420 msec
[1624408188266] [0x6b0044] CHIP: [IN] Sending secure msg on generic transport
[1624408188266] [0x6b0044] CHIP: [IN] Secure msg send status No Error
[1624408188266] [0x6b0044] CHIP: [DMG] ICR moving to [   Sending]
[1624408188266] [0x6b0044] CHIP: [CTL] Sent operational certificate to the device
[1624408188266] [0x6b0044] CHIP: [DMG] ICR moving to [Uninitiali]
[1624408189250] [0x6b00dd] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 1
[1624408189250] [0x6b00dd] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44252
[1624408189250] [0x6b00dd] CHIP: [DMG] InvokeCommand =
[1624408189250] [0x6b00dd] CHIP: [DMG] {
[1624408189250] [0x6b00dd] CHIP: [DMG] 	CommandList =
[1624408189250] [0x6b00dd] CHIP: [DMG] 	[
[1624408189250] [0x6b00dd] CHIP: [DMG] 		CommandDataElement =
[1624408189250] [0x6b00dd] CHIP: [DMG] 		{
[1624408189250] [0x6b00dd] CHIP: [DMG] 			CommandPath =
[1624408189250] [0x6b00dd] CHIP: [DMG] 			{
[1624408189250] [0x6b00dd] CHIP: [DMG] 				EndpointId = 0x0,
[1624408189250] [0x6b00dd] CHIP: [DMG] 				ClusterId = 0x3e,
[1624408189250] [0x6b00dd] CHIP: [DMG] 				CommandId = 0x6,
[1624408189250] [0x6b00dd] CHIP: [DMG] 			},
[1624408189250] [0x6b00dd] CHIP: [DMG]
[1624408189250] [0x6b00dd] CHIP: [DMG] 			StatusElement =
[1624408189250] [0x6b00dd] CHIP: [DMG] 			{
[1624408189250] [0x6b00dd] CHIP: [DMG] 				GeneralCode = 0x0,
[1624408189250] [0x6b00dd] CHIP: [DMG] 				ProtocolId = 0x5,
[1624408189250] [0x6b00dd] CHIP: [DMG] 				protocolCode = 0x0,
[1624408189250] [0x6b00dd] CHIP: [DMG] 			},
[1624408189250] [0x6b00dd] CHIP: [DMG]
[1624408189250] [0x6b00dd] CHIP: [DMG] 		},
[1624408189250] [0x6b00dd] CHIP: [DMG]
[1624408189250] [0x6b00dd] CHIP: [DMG] 	],
[1624408189250] [0x6b00dd] CHIP: [DMG]
[1624408189250] [0x6b00dd] CHIP: [DMG] }
[1624408189250] [0x6b00dd] CHIP: [ZCL] DefaultResponse:
[1624408189250] [0x6b00dd] CHIP: [ZCL]   Transaction: 0x10cd18cf8
[1624408189250] [0x6b00dd] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624408189250] [0x6b00dd] CHIP: [CTL] Device confirmed that it has received the operational certificate
[1624408189250] [0x6b00dd] CHIP: [CTL] Operational credentials provisioned on device 0x7ffee308ad88
[1624408189252] [0x6b00dd] CHIP: [TOO] Secure Pairing Success
[1624408189253] [0x6b00dd] CHIP: [TOO] Pairing Success
[1624408189253] [0x6b00dd] CHIP: [DMG] ICR moving to [Initialize]
[1624408189253] [0x6b00dd] CHIP: [DMG] ICR moving to [AddCommand]
[1624408189253] [0x6b00dd] CHIP: [IN] Connection from 'BLE' expired
[1624408189253] [0x6b00dd] CHIP: [CTL] OnConnectionExpired was called for unknown device, ignoring it.
[1624408189253] [0x6b00dd] CHIP: [IN] New pairing for device 0x0000000000bc5c01, key 0!!
[1624408189253] [0x6b00dd] CHIP: [IN] Secure message was encrypted: Msg ID 4
[1624408189253] [0x6b00dd] CHIP: [IN] Encrypted message 0x70000e6db790 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44253.
[1624408189253] [0x6b00dd] CHIP: [IN] Sending msg 0x70000e6db790 to 0x0000000000BC5C01 at utc time: 552373407 msec
[1624408189253] [0x6b00dd] CHIP: [IN] Sending secure msg on generic transport
[1624408189253] [0x6b00dd] CHIP: [IN] Secure msg send status No Error
[1624408189253] [0x6b00dd] CHIP: [DMG] ICR moving to [   Sending]
[1624408189253] [0x6b00dd] CHIP: [DMG] ICR moving to [Uninitiali]
[1624408190015] [0x6b00dd] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 1
[1624408190015] [0x6b00dd] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44253
[1624408190015] [0x6b00dd] CHIP: [DMG] InvokeCommand =
[1624408190015] [0x6b00dd] CHIP: [DMG] {
[1624408190015] [0x6b00dd] CHIP: [DMG] 	CommandList =
[1624408190015] [0x6b00dd] CHIP: [DMG] 	[
[1624408190015] [0x6b00dd] CHIP: [DMG] 		CommandDataElement =
[1624408190015] [0x6b00dd] CHIP: [DMG] 		{
[1624408190015] [0x6b00dd] CHIP: [DMG] 			CommandPath =
[1624408190015] [0x6b00dd] CHIP: [DMG] 			{
[1624408190015] [0x6b00dd] CHIP: [DMG] 				EndpointId = 0x0,
[1624408190015] [0x6b00dd] CHIP: [DMG] 				ClusterId = 0x31,
[1624408190015] [0x6b00dd] CHIP: [DMG] 				CommandId = 0x2,
[1624408190015] [0x6b00dd] CHIP: [DMG] 			},
[1624408190015] [0x6b00dd] CHIP: [DMG]
[1624408190015] [0x6b00dd] CHIP: [DMG] 			StatusElement =
[1624408190015] [0x6b00dd] CHIP: [DMG] 			{
[1624408190015] [0x6b00dd] CHIP: [DMG] 				GeneralCode = 0x0,
[1624408190015] [0x6b00dd] CHIP: [DMG] 				ProtocolId = 0x5,
[1624408190015] [0x6b00dd] CHIP: [DMG] 				protocolCode = 0x0,
[1624408190015] [0x6b00dd] CHIP: [DMG] 			},
[1624408190015] [0x6b00dd] CHIP: [DMG]
[1624408190015] [0x6b00dd] CHIP: [DMG] 		},
[1624408190015] [0x6b00dd] CHIP: [DMG]
[1624408190015] [0x6b00dd] CHIP: [DMG] 	],
[1624408190015] [0x6b00dd] CHIP: [DMG]
[1624408190015] [0x6b00dd] CHIP: [DMG] }
[1624408190015] [0x6b00dd] CHIP: [ZCL] DefaultResponse:
[1624408190015] [0x6b00dd] CHIP: [ZCL]   Transaction: 0x10cd18e08
[1624408190015] [0x6b00dd] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624408190015] [0x6b00dd] CHIP: [TOO] AddNetworkResponse
[1624408190015] [0x6b00dd] CHIP: [DMG] ICR moving to [Initialize]
[1624408190015] [0x6b00dd] CHIP: [DMG] ICR moving to [AddCommand]
[1624408190015] [0x6b00dd] CHIP: [IN] Secure message was encrypted: Msg ID 5
[1624408190015] [0x6b00dd] CHIP: [IN] Encrypted message 0x70000e6db8d0 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44254.
[1624408190015] [0x6b00dd] CHIP: [IN] Sending msg 0x70000e6db8d0 to 0x0000000000BC5C01 at utc time: 552374169 msec
[1624408190015] [0x6b00dd] CHIP: [IN] Sending secure msg on generic transport
[1624408190015] [0x6b00dd] CHIP: [IN] Secure msg send status No Error
[1624408190015] [0x6b00dd] CHIP: [DMG] ICR moving to [   Sending]
[1624408190015] [0x6b00dd] CHIP: [DMG] ICR moving to [Uninitiali]
[1624408190870] [0x6b00dd] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 1
[1624408190870] [0x6b00dd] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44254
[1624408190870] [0x6b00dd] CHIP: [DMG] InvokeCommand =
[1624408190870] [0x6b00dd] CHIP: [DMG] {
[1624408190870] [0x6b00dd] CHIP: [DMG] 	CommandList =
[1624408190870] [0x6b00dd] CHIP: [DMG] 	[
[1624408190870] [0x6b00dd] CHIP: [DMG] 		CommandDataElement =
[1624408190870] [0x6b00dd] CHIP: [DMG] 		{
[1624408190870] [0x6b00dd] CHIP: [DMG] 			CommandPath =
[1624408190870] [0x6b00dd] CHIP: [DMG] 			{
[1624408190870] [0x6b00dd] CHIP: [DMG] 				EndpointId = 0x0,
[1624408190870] [0x6b00dd] CHIP: [DMG] 				ClusterId = 0x31,
[1624408190870] [0x6b00dd] CHIP: [DMG] 				CommandId = 0xc,
[1624408190870] [0x6b00dd] CHIP: [DMG] 			},
[1624408190870] [0x6b00dd] CHIP: [DMG]
[1624408190870] [0x6b00dd] CHIP: [DMG] 			StatusElement =
[1624408190870] [0x6b00dd] CHIP: [DMG] 			{
[1624408190870] [0x6b00dd] CHIP: [DMG] 				GeneralCode = 0x1,
[1624408190870] [0x6b00dd] CHIP: [DMG] 				ProtocolId = 0x5,
[1624408190870] [0x6b00dd] CHIP: [DMG] 				protocolCode = 0x1,
[1624408190870] [0x6b00dd] CHIP: [DMG] 			},
[1624408190870] [0x6b00dd] CHIP: [DMG]
[1624408190870] [0x6b00dd] CHIP: [DMG] 		},
[1624408190870] [0x6b00dd] CHIP: [DMG]
[1624408190870] [0x6b00dd] CHIP: [DMG] 	],
[1624408190870] [0x6b00dd] CHIP: [DMG]
[1624408190870] [0x6b00dd] CHIP: [DMG] }
[1624408190870] [0x6b00dd] CHIP: [ZCL] DefaultResponse:
[1624408190870] [0x6b00dd] CHIP: [ZCL]   Transaction: 0x10cd18cf8
[1624408190870] [0x6b00dd] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_FAILURE (0x01)
[1624408190870] [0x6b00dd] CHIP: [TOO] Default Failure Response: 0x01
[1624408190870] [0x6b00dd] CHIP: [DMG] ICR moving to [Uninitiali]
[1624408190870] [0x6b003e] CHIP: [TOO] Run command failure: CHIP Error 4172 (0x0000104C): Internal error
[1624408190870] [0x6b003e] CHIP: [CTL] Shutting down the commissioner
[1624408190870] [0x6b003e] CHIP: [CTL] Shutting down the controller
[1624408190870] [0x6b003e] CHIP: [DL] Inet Layer shutdown
[1624408190870] [0x6b003e] CHIP: [DL] BLE layer shutdown
[1624408190870] [0x6b003e] CHIP: [IN] Clearing BLE pending packets.
[1624408190870] [0x6b003e] CHIP: [BLE] Auto-closing end point's BLE connection.
[1624408190870] [0x6b003e] CHIP: [DL] System Layer shutdown
---------- Device Logs ------------------------
[1624408190.286210][1520283] CHIP:NP: LinuxNetworkProvisioningDelegate: SSID: Partyguys
[1624408190.291369][1520283] CHIP:DL: wpa_supplicant: failed to add network: Partyguys: GDBus.Error:org.freedesktop.DBus.Error.InvalidArgs: invalid message format
[1624408190.291456][1520283] CHIP:NP: Failed to connect to WiFi network: CHIP Error 4172 (0x0000104C): Internal error
[1624408190.291517][1520283] CHIP:DMG: ICR moving to [AddCommand]
[1624408190.291658][1520283] CHIP:IN: Secure message was encrypted: Msg ID 5
[1624408190.291709][1520283] CHIP:IN: Encrypted message 0xffffd1889690 from 0x0000000000BC5C01 to 0x000000000001B669 of type 9 and protocolId 5 on exchange 44254.
[1624408190.291760][1520283] CHIP:IN: Sending msg 0xffffd1889690 to 0x000000000001B669 at utc time: 720929152 msec
[1624408190.291800][1520283] CHIP:IN: Sending secure msg on generic transport
[1624408190.291843][1520283] CHIP:IN: Secure msg send status No Error
[1624408190.291882][1520283] CHIP:DMG: ICR moving to [   Sending]
[1624408190.291925][1520283] CHIP:DMG: ICR moving to [Uninitiali]
[1624408190.417518][1520286] CHIP:BLE: Indication confirmation, 0xffffac044e10
[1624408190.506870][1520286] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624408190.507499][1520286] CHIP:BLE: Write request received debug 0xffffac044e10
[1624408190.507722][1520286] CHIP:BLE: Indication confirmation, 0xffffac044e10
[1624408190.687350][1520286] CHIP:BLE: Indication confirmation, 0xffffac044e10
[1624408190.821961][1520286] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624408190.822187][1520286] CHIP:BLE: Write request received debug 0xffffac044e10
[1624408190.822746][1520286] CHIP:BLE: Indication confirmation, 0xffffac044e10
[1624408190.957603][1520286] CHIP:BLE: Indication confirmation, 0xffffac044e10
[1624408191.274139][1520286] CHIP:DL: Bluez disconnected
[1624408191.274215][1520286] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1624408191.274413][1520283] CHIP:IN: Clearing BLE pending packets.
[1624408191.274571][1520286] CHIP:BLE: Indication confirmation, (nil)
[1624408191.275036][1520283] CHIP:BLE: no endpoint for BLE sent data ack
^C

Hard to say what's going on there without more details about what exact commands are being run and whatnot.

@bzbarsky-apple do you need any additional info ?

Things like knowing what device is being commissioned might have been useful.  That said, device log says:
 [1624408190.291369][1520283] CHIP:DL: wpa_supplicant: failed to add network: Partyguys: GDBus.Error:org.freedesktop.DBus.Error.InvalidArgs: invalid message format

Is the device being commissioned a Linux device?
If so, it's worth checking whether the right data is landing inside src/platform/Linux/ConnectivityManagerImpl.cpp at ConnectivityManagerImpl::ProvisionWiFiNetwork.  Past that, @yufengwangca any ideas what might be going on here?

@bzbarsky-apple the device is a raspi (running ubuntu server OS).

From my test, I am able to provision the rp4 to my home network using chip-shell. When I try to provision the rp4 using chip-tool from mac w/o #7806, I observed different errors:

On the mac side
yufengs-mbp:host yufengw$ ./chip-tool pairing ble-wifi test-2g 12345678 12344321 20202021 3840
CHIP: [ZCL] Using ZAP configuration...
CHIP: [ZCL] deactivate report event
CHIP: [DL] _Init
CHIP: [IN] TransportMgr initialized
CHIP: [IN] local node id is 0x000000000001b669
CHIP: [ZCL] Using ZAP configuration...
CHIP: [ZCL] deactivate report event
CHIP: [DL] CHIP task running
CHIP: [BLE] NewConnection
CHIP: [BLE] CBManagerState: ON
CHIP: [BLE] Connecting to device with discriminator: 3840
CHIP: [BLE] Warning: OnBleConnectionComplete is called multiple times for the same peripheral.
CHIP: [BLE] subscribe complete, ep = 0x1049caf98
CHIP: [BLE] peripheral chose BTP version 3; central expected between 2 and 3
CHIP: [BLE] using BTP fragment sizes rx 20 / tx 128.
CHIP: [BLE] local and remote recv window size = 3
CHIP: [BLE] Assigned local session key ID 0
CHIP: [BLE] SessionEstablishmentExchangeDispatch::SendMessageImpl mBLETransport 0x7fcb17708b90, mTransportMgr 0x7fcb17708a60
CHIP: [BLE] Sending message using BLE transport
CHIP: [BLE] Sent PBKDF param request
CHIP: [BLE] Received PBKDF param response
CHIP: [BLE] SessionEstablishmentExchangeDispatch::SendMessageImpl mBLETransport 0x7fcb17708b90, mTransportMgr 0x7fcb17708a60
CHIP: [BLE] Sending message using BLE transport
CHIP: [BLE] Sent spake2p msg1
CHIP: [BLE] Received spake2p msg2
CHIP: [BLE] Peer assigned session key ID 0
CHIP: [BLE] SessionEstablishmentExchangeDispatch::SendMessageImpl mBLETransport 0x7fcb17708b90, mTransportMgr 0x7fcb17708a60
CHIP: [BLE] Sending message using BLE transport
CHIP: [BLE] Sent spake2p msg3
CHIP: [IN] New pairing for device 0x0000000000bc5c01, key 0!!
CHIP: [CTL] Remote device completed SPAKE2+ handshake

CHIP: [TOO] OnNetworkCredentialsRequested
CHIP: [NP] Sending Network Creds
CHIP: [IN] Secure message was encrypted: Msg ID 0
CHIP: [IN] Sending msg from 0x000000000001b669 to 0x0000000000bc5c01 at utc time:<PHONE_NUMBER> msec
CHIP: [IN] Sending secure msg on connection specific transport
CHIP: [IN] Secure msg send status No Error
CHIP: [TOO] Secure Pairing Success
CHIP: [BLE] ack recv timeout, closing ep 0x1049caf98
CHIP: [CTL] Remote device failed in network provisioning
CHIP: [TOO] Network Provisioning Failed
CHIP: [BLE] CancelConnection
CHIP: [TOO] Pairing Failure: Ble Error 6024 (0x00001788): Message fragment acknowledgement timed out
CHIP: [CTL] Shutting down the commissioner
CHIP: [CTL] Shutting down the controller
CHIP: [DL] System Layer shutdown
CHIP: [DL] Inet Layer shutdown
CHIP: [IN] Async DNS worker thread woke up.
CHIP: [IN] Async DNS worker thread exiting.
CHIP: [IN] Async DNS worker thread woke up.

On RP4 side
CHIP:DL: Device 8C:85:90:58:49:03 (Path: /org/bluez/hci0/dev_8C_85_90_58_49_03) Connected
CHIP:DL: BluezCharacteristicAcquireWrite is called, conn: 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: local and remote recv window sizes = 3
CHIP:BLE: selected BTP version 3
CHIP:BLE: using BTP fragment sizes rx 128 / tx 20.
CHIP:DL: CHIPoBLE subscribe received
CHIP:DL: HandlePlatformSpecificBLEEvent 32777
CHIP:DL: Receive kCHIPoBLEConnectionEstablished
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:EM: ec pos: 0, id: 16807, Delegate: 0xcce082e8
CHIP:BLE: Received PBKDF param request
CHIP:BLE: SessionEstablishmentExchangeDispatch::SendMessageImpl mBLETransport 0xaaaae4587f10, mTransportMgr 0xaaaacce07a50
CHIP:BLE: Sending message using BLE transport
CHIP:BLE: Sent PBKDF param response
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: Received spake2p msg1
CHIP:BLE: Peer assigned session key ID 0
CHIP:BLE: SessionEstablishmentExchangeDispatch::SendMessageImpl mBLETransport 0xaaaae4587f10, mTransportMgr 0xaaaacce07a50
CHIP:BLE: Sending message using BLE transport
CHIP:BLE: Sent spake2p msg2
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: Received spake2p msg3
CHIP:BLE: Missing node id in rendezvous parameters. Node ID is required until opcerts are implemented
CHIP:IN: New pairing for device 0x0000000000000000, key 0!!
CHIP:SVR: Device completed SPAKE2+ handshake
CHIP:BLE: Indication confirmation, 0xffffa002fcc0
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:EM: ec pos: 1, id: 16808, Delegate: 0xcce08be0
CHIP:NP: Received kWiFiAssociationRequest.

CHIP:NP: LinuxNetworkProvisioningDelegate: SSID: test-2g
(process:20763): GLib-GIO-CRITICAL **: 18:30:34.896: g_dbus_proxy_call_sync_internal: assertion 'G_IS_DBUS_PROXY (proxy)' failed
CHIP:DL: wpa_supplicant: failed to add network: test-2g: unknown error
CHIP:NP: Failed to connect to WiFi network: CHIP Error 4172 (0x0000104C): Internal error
CHIP:NP: Failed in HandleNetworkProvisioningMessage. error CHIP Error 4172 (0x0000104C): Internal error
CHIP:SVR: OnRendezvousStatusUpdate: CHIP Error 4172 (0x0000104C): Internal error
CHIP:SVR: Persisting admin ID 0, next available 1
CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
CHIP:BLE: Releasing end point's BLE connection back to application.
CHIP:BLE: Got notification regarding chip connection closure
CHIP:SVR: OnRendezvousError: CHIP Error 4172 (0x0000104C): Internal error
CHIP:DL: UnregisterAdvertisement complete
CHIP:DL: HandlePlatformSpecificBLEEvent 16395
CHIP:DL: CHIPoBLE advertising stopped
CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
CHIP:BLE: Write request received debug 0xffffa002fcc0
CHIP:BLE: Releasing end point's BLE connection back to application.
CHIP:BLE: Got notification regarding chip connection closure
CHIP:BLE: HandleChipConnectionReceived failed, err = 6018
CHIP:BLE: failed handle new chip BLE connection, status = 6018
CHIP:DL: Bluez disconnected
CHIP:DL: Bluez notify CHIPoBluez connection disconnected

Test Setp Details:
Accessory : Lighting App on Raspi running Ubutun Server OS 20.10 , App built with 'scripts/examples/gn_build_example.sh examples/lighting-app/linux out/lighting-app' . App launched with cmd ' sudo ./out/lighting-app/chip-lighting-app --wifi
'
Controller : Chip-tool on Mac , built with instructions https://github.com/project-chip/connectedhomeip/tree/master/examples/chip-tool , launch chip tool with cmd ' ./out/debug/chip-tool pairing ble-wifi   12344321 20202021 3840
With ToT (129c67e8e7b60a959aa3b781d45c523635347196) on both chip-tool and lighting app, I see the  Ble endpoint pool FULL error followed by PASE session timeout with BLE
Mac log
% ./out/debug/chip-tool pairing ble-wifi   12344321 20202021 3840
[1624993699573] [0x23b659] CHIP: [DL] _Init
[1624993699573] [0x23b659] CHIP: [IN] TransportMgr initialized
[1624993699573] [0x23b659] CHIP: [DIS] Init admin pairing table with server storage
[1624993699573] [0x23b659] CHIP: [IN] Loading certs from KVS
[1624993699573] [0x23b659] CHIP: [IN] local node id is 0x000000000001B669
[1624993699573] [0x23b659] CHIP: [ZCL] Using ZAP configuration...
[1624993699574] [0x23b659] CHIP: [ZCL] deactivate report event
[1624993699574] [0x23b659] CHIP: [CTL] Getting operational keys
[1624993699574] [0x23b659] CHIP: [CTL] Generating credentials
[1624993699574] [0x23b659] CHIP: [CTL] Loaded credentials successfully
[1624993699574] [0x23b65c] CHIP: [BLE] NewConnection
[1624993699576] [0x23b65c] CHIP: [SC] Assigned local session key ID 1
[1624993699577] [0x23b65c] CHIP: [IN] Message appended to BLE send queue
[1624993699577] [0x23b65c] CHIP: [SC] Sent PBKDF param request
[1624993703450] [0x23b65c] CHIP: [BLE] CBManagerState: ON
[1624993713092] [0x23b65c] CHIP: [BLE] Connecting to device with discriminator: 3840
[1624993715964] [0x23b65c] CHIP: [IN] BleConnectionComplete: endPoint 0x10d9827d8
[1624993715964] [0x23b65c] CHIP: [BLE] Ble endpoint pool FULL
[1624993715964] [0x23b65c] CHIP: [IN] Clearing BLE pending packets.
[1624993715964] [0x23b65c] CHIP: [IN] BleConnection Error: Ble Error 6002 (0x00001772): No more BLE endpoints
[1624993716233] [0x23b65d] CHIP: [BLE] subscribe complete, ep = 0x10d9827d8
[1624993716236] [0x23b65c] CHIP: [BLE] peripheral chose BTP version 3; central expected between 2 and 3
[1624993716236] [0x23b65c] CHIP: [BLE] using BTP fragment sizes rx 20 / tx 128.
[1624993716236] [0x23b65c] CHIP: [BLE] local and remote recv window size = 3
[1624993716236] [0x23b65c] CHIP: [IN] BLE EndPoint 0x10d9827d8 Connection Complete
[1624993729578] [0x23b65d] CHIP: [TOO] Pairing Failure: CHIP Error 4050 (0x00000FD2): Timeout
[1624993729578] [0x23b65d] CHIP: [SC] PASESession timed out while waiting for a response from the peer. Expected message type was 33
[1624993729578] [0x23b65d] CHIP: [TOO] Secure Pairing Failed
[1624993729578] [0x23b659] CHIP: [TOO] Run command failure: CHIP Error 4050 (0x00000FD2): Timeout
[1624993729578] [0x23b65d] CHIP: [TOO] Pairing Failure: CHIP Error 4050 (0x00000FD2): Timeout
[1624993729578] [0x23b659] CHIP: [CTL] Shutting down the commissioner
[1624993729578] [0x23b659] CHIP: [CTL] Shutting down the controller
[1624993729578] [0x23b659] CHIP: [DL] Inet Layer shutdown
[1624993729578] [0x23b659] CHIP: [DL] BLE layer shutdown
[1624993729578] [0x23b659] CHIP: [IN] Clearing BLE pending packets.
[1624993729578] [0x23b659] CHIP: [BLE] Auto-closing end point's BLE connection.
[1624993729578] [0x23b659] CHIP: [DL] System Layer shutdown
Device side log
$ sudo ./out/lighting-app/chip-lighting-app --wifi
[1624993695.183161][28913] CHIP:DL: Device Configuration:
[1624993695.183215][28913] CHIP:DL:   Serial Number: TEST_SN
[1624993695.183240][28913] CHIP:DL:   Vendor Id: 9050 (0x235A)
[1624993695.183257][28913] CHIP:DL:   Product Id: 65279 (0xFEFF)
[1624993695.183277][28913] CHIP:DL:   Product Revision: 1
[1624993695.183296][28913] CHIP:DL:   Setup Pin Code: 20202021
[1624993695.183314][28913] CHIP:DL:   Setup Discriminator: 3840 (0xF00)
[1624993695.183333][28913] CHIP:DL:   Manufacturing Date: (not set)
[1624993695.183350][28913] CHIP:DL:   Device Type: 257 (0x101)
[1624993695.183414][28913] CHIP:SVR: SetupQRCode: [MT:YNJV7VSC00KA0648G00]
[1624993695.183438][28913] CHIP:SVR: Copy/paste the below URL in a browser to see the QR Code:
[1624993695.183452][28913] CHIP:SVR: https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3AYNJV7VSC00KA0648G00
[1624993695.183480][28913] CHIP:SVR: Manual pairing code: [34970112332]
[1624993695.183924][28913] CHIP:ZCL: Using ZAP configuration...
[1624993695.184037][28913] CHIP:ZCL: deactivate report event
[1624993695.184057][28913] CHIP:ZCL: OpCreds: Initiating OpCreds cluster by writing fabrics list from admin pairing table.
[1624993695.184072][28913] CHIP:DIS: Set the admin pairing table delegate
[1624993695.184085][28913] CHIP:ZCL: OpCreds: Call to writeAdminsIntoFabricsListAttribute
[1624993695.184101][28913] CHIP:ZCL: OpCreds: Stored 0 admins in fabrics list attribute.
[1624993695.184122][28913] CHIP:ZCL: Unknown cluster ID: 40
[1624993695.184139][28913] CHIP:ZCL: Unknown cluster ID: 40
[1624993695.184153][28913] CHIP:ZCL: Unknown cluster ID: 40
[1624993695.184169][28913] CHIP:ZCL: Unknown cluster ID: 40
[1624993695.184184][28913] CHIP:ZCL: Unknown cluster ID: 40
[1624993695.184206][28913] CHIP:ZCL: Unknown cluster ID: 40
[1624993695.184221][28913] CHIP:ZCL: Unknown cluster ID: 40
[1624993695.184236][28913] CHIP:ZCL: Unknown cluster ID: 40
[1624993695.184452][28913] CHIP:DIS: Init admin pairing table with server storage
[1624993695.184650][28913] CHIP:IN: TransportMgr initialized
[1624993695.184903][28913] CHIP:DL: writing settings to file (/tmp/chip_counters.ini.tmp)
[1624993695.185482][28913] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1624993695.185532][28913] CHIP:DL: NVS set: chip-counters/GlobalMCTR = 6000 (0x1770)
[1624993695.185555][28913] CHIP:IN: local node id is 0x0000000000BC5C01
[1624993695.185610][28913] CHIP:DL: wpa_supplicant: _IsWiFiStationProvisioned: interface not connected
[1624993695.185692][28913] CHIP:SC: Assigned local session key ID 0
[1624993695.185715][28913] CHIP:SC: Waiting for PBKDF param request
[1624993695.185733][28913] CHIP:DIS: Start dns-sd server
[1624993695.187483][28913] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: Inet Error 1016 (0x000003F8): Address not found
[1624993695.188621][28916] CHIP:DL: wpa_supplicant: connected to wpa_supplicant proxy
[1624993695.189496][28913] CHIP:DIS: CHIP minimal mDNS started advertising.
[1624993695.190009][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.190130][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.190235][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.190259][28916] CHIP:DL: wpa_supplicant: WiFi interface: /fi/w1/wpa_supplicant1/Interfaces/0
[1624993695.190349][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.190452][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.190549][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.190644][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.190740][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.190772][28913] CHIP:DL: wpa_supplicant: _IsWiFiStationProvisioned: interface not connected
[1624993695.191208][28913] CHIP:DIS: Using wifi MAC for hostname
[1624993695.191275][28913] CHIP:DL: rotatingDeviceId: 00007C5F6E176CD40F68685D100A1CF8A98B
[1624993695.191301][28913] CHIP:DL: wpa_supplicant: _IsWiFiStationProvisioned: interface not connected
[1624993695.191332][28913] CHIP:DIS: Advertise commission parameter vendorID=9050 productID=65279 discriminator=3840/00
[1624993695.191406][28913] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'.
[1624993695.191437][28913] CHIP:SVR: Server Listening...
[1624993695.191759][28919] CHIP:DL: TRACE: Bluez mainloop starting Thread
[1624993695.192365][28916] CHIP:DL: TRACE: Bus acquired for name MATTER-3840
[1624993695.192665][28916] CHIP:DL: CREATE service object at /chipoble/70f1/service
[1624993695.193674][28916] CHIP:DL: Create characteristic object at /chipoble/70f1/service/c1
[1624993695.194276][28916] CHIP:DL: Create characteristic object at /chipoble/70f1/service/c2
[1624993695.194680][28916] CHIP:DL: CHIP BTP C1 /chipoble/70f1/service
[1624993695.194711][28916] CHIP:DL: CHIP BTP C2 /chipoble/70f1/service
[1624993695.194734][28916] CHIP:DL: CHIP_ENABLE_ADDITIONAL_DATA_ADVERTISING is TRUE
[1624993695.194761][28916] CHIP:DL: Create characteristic object at /chipoble/70f1/service/c3
[1624993695.195164][28916] CHIP:DL: rotatingDeviceId: 00007C5F6E176CD40F68685D100A1CF8A98B
[1624993695.195228][28916] CHIP:DL: CHIP BTP C3 /chipoble/70f1/service
[1624993695.202524][28913] CHIP:DL: PlatformBlueZInit init success
[1624993695.208951][28916] CHIP:DL: wpa_supplicant: connected to wpa_supplicant interface proxy
[1624993695.209912][28916] CHIP:DL: BluezPeripheralRegisterAppDone done
[1624993695.210147][28913] CHIP:DL: HandlePlatformSpecificBLEEvent 16392
[1624993695.210230][28916] CHIP:DL: Create adv object at /chipoble/70f1/advertising
[1624993695.210730][28916] CHIP:DL: SET service data to {'0xFFF6': <[byte 0x00, 0x00, 0x0f, 0x5a, 0x23, 0xff, 0xfe]>}
[1624993695.211546][28913] CHIP:DL: HandlePlatformSpecificBLEEvent 16393
[1624993695.211594][28913] CHIP:DL: CHIPoBLE advertising config complete
[1624993695.219536][28916] CHIP:DL: RegisterAdvertisement complete
[1624993695.219685][28913] CHIP:DL: HandlePlatformSpecificBLEEvent 16394
[1624993695.339275][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993695.339415][28913] CHIP:DIS: Broadcasting mDns reply
[1624993712.388996][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993712.389090][28913] CHIP:DIS: Broadcasting mDns reply
[1624993713.825888][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993713.825960][28913] CHIP:DIS: Broadcasting mDns reply
[1624993715.734942][28916] CHIP:DL: Device 14:7D:DA:8F:84:62 (Path: /org/bluez/hci0/dev_14_7D_DA_8F_84_62) Connected
[1624993716.177997][28916] CHIP:DL: BluezCharacteristicAcquireWrite is called, conn: 0xffff78046db0
[1624993716.178945][28916] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624993716.179045][28916] CHIP:BLE: Write request received debug 0xffff78046db0
[1624993716.179101][28913] CHIP:BLE: local and remote recv window sizes = 3
[1624993716.179123][28913] CHIP:BLE: selected BTP version 3
[1624993716.179137][28913] CHIP:BLE: using BTP fragment sizes rx 128 / tx 20.
[1624993716.298379][28916] CHIP:DL: CHIPoBLE subscribe received
[1624993716.298424][28913] CHIP:IN: BLE EndPoint 0xaaaae028f550 Connection Complete
[1624993716.298456][28913] CHIP:DL: HandlePlatformSpecificBLEEvent 32777
[1624993716.298472][28913] CHIP:DL: Receive kCHIPoBLEConnectionEstablished
[1624993716.327708][28916] CHIP:BLE: Indication confirmation, 0xffff78046db0
[1624993718.832403][28916] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624993718.832574][28916] CHIP:BLE: Write request received debug 0xffff78046db0
[1624993721.352817][28916] CHIP:BLE: Indication confirmation, 0xffff78046db0
[1624993723.857471][28916] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624993723.857626][28916] CHIP:BLE: Write request received debug 0xffff78046db0
[1624993726.377857][28916] CHIP:BLE: Indication confirmation, 0xffff78046db0
[1624993728.882575][28916] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624993728.882731][28916] CHIP:BLE: Write request received debug 0xffff78046db0
[1624993729.754269][28916] CHIP:DL: Bluez disconnected
[1624993729.754310][28916] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1624993729.754364][28913] CHIP:IN: Clearing BLE pending packets.
[1624993808.036618][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993808.036690][28913] CHIP:DIS: Broadcasting mDns reply
[1624993906.591417][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993906.591496][28913] CHIP:DIS: Broadcasting mDns reply
[1624993922.116465][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624993922.116538][28913] CHIP:DIS: Broadcasting mDns reply
[1624994004.180967][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624994004.181040][28913] CHIP:DIS: Broadcasting mDns reply
[1624994019.915434][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624994019.915513][28913] CHIP:DIS: Broadcasting mDns reply
[1624994027.220259][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624994027.220334][28913] CHIP:DIS: Broadcasting mDns reply
[1624994037.972906][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624994037.972993][28913] CHIP:DIS: Broadcasting mDns reply
[1624994047.860302][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624994047.860377][28913] CHIP:DIS: Broadcasting mDns reply
[1624994053.619909][28913] CHIP:DIS: Replying to DNS-SD service listing request
[1624994053.619993][28913] CHIP:DIS: Broadcasting mDns reply
With #7806 fixes the BLE endpoint Full issue and moves fwd with other parts of provisioning flow.
Mac Log
chaitanyajandhyala@chaitanyas-Mac-mini-2 chip-tool % ./out/debug/chip-tool pairing ble-wifi   12344321 20202021 3840
[1624994986546] [0x23fc04] CHIP: [DL] _Init
[1624994986547] [0x23fc04] CHIP: [IN] TransportMgr initialized
[1624994986547] [0x23fc04] CHIP: [DIS] Init admin pairing table with server storage
[1624994986547] [0x23fc04] CHIP: [IN] Loading certs from KVS
[1624994986547] [0x23fc04] CHIP: [IN] local node id is 0x000000000001B669
[1624994986547] [0x23fc04] CHIP: [ZCL] Using ZAP configuration...
[1624994986547] [0x23fc04] CHIP: [ZCL] deactivate report event
[1624994986547] [0x23fc04] CHIP: [CTL] Getting operational keys
[1624994986547] [0x23fc04] CHIP: [CTL] Generating credentials
[1624994986547] [0x23fc04] CHIP: [CTL] Loaded credentials successfully
[1624994986548] [0x23fc08] CHIP: [BLE] NewConnection
[1624994986549] [0x23fc08] CHIP: [SC] Assigned local session key ID 3
[1624994986549] [0x23fc08] CHIP: [IN] Message appended to BLE send queue
[1624994986549] [0x23fc08] CHIP: [SC] Sent PBKDF param request
[1624994986604] [0x23fc08] CHIP: [BLE] CBManagerState: ON
[1624994996470] [0x23fc09] CHIP: [BLE] Connecting to device with discriminator: 3840
[1624994999330] [0x23fc09] CHIP: [IN] BleConnectionComplete: endPoint 0x1098df858
[1624994999599] [0x23fc09] CHIP: [BLE] subscribe complete, ep = 0x1098df858
[1624994999604] [0x23fc09] CHIP: [BLE] peripheral chose BTP version 3; central expected between 2 and 3
[1624994999604] [0x23fc09] CHIP: [BLE] using BTP fragment sizes rx 20 / tx 128.
[1624994999604] [0x23fc09] CHIP: [BLE] local and remote recv window size = 3
[1624994999604] [0x23fc09] CHIP: [IN] BLE EndPoint 0x1098df858 Connection Complete
[1624994999752] [0x23fc08] CHIP: [EM] Received message of type 33 and protocolId 0 on exchange 44249
[1624994999752] [0x23fc08] CHIP: [SC] Received PBKDF param response
[1624994999752] [0x23fc08] CHIP: [SC] Sent spake2p msg1
[1624994999962] [0x23fc08] CHIP: [EM] Received message of type 35 and protocolId 0 on exchange 44249
[1624994999962] [0x23fc08] CHIP: [SC] Received spake2p msg2
[1624994999962] [0x23fc08] CHIP: [SC] Peer assigned session key ID 0
[1624994999963] [0x23fc08] CHIP: [SC] Sent spake2p msg3
[1624994999963] [0x23fc08] CHIP: [IN] New pairing for device 0x0000000000bc5c01, key 0!!
[1624994999963] [0x23fc08] CHIP: [CTL] Remote device completed SPAKE2+ handshake
[1624994999963] [0x23fc08] CHIP: [CTL] Sending root certificate to the device
[1624994999963] [0x23fc08] CHIP: [DMG] ICR moving to [Initialize]
[1624994999963] [0x23fc08] CHIP: [DMG] ICR moving to [AddCommand]
[1624994999963] [0x23fc08] CHIP: [IN] Secure message was encrypted: Msg ID 0
[1624994999963] [0x23fc08] CHIP: [IN] Encrypted message 0x70000bc5cc30 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44250.
[1624994999963] [0x23fc08] CHIP: [IN] Sending msg 0x70000bc5cc30 to 0x0000000000BC5C01 at utc time: 332740538 msec
[1624994999963] [0x23fc08] CHIP: [IN] Sending secure msg on generic transport
[1624994999963] [0x23fc08] CHIP: [IN] Secure msg send status No Error
[1624994999963] [0x23fc08] CHIP: [DMG] ICR moving to [   Sending]
[1624994999963] [0x23fc08] CHIP: [CTL] Sent root certificate to the device
[1624995000232] [0x23fc09] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 3
[1624995000232] [0x23fc09] CHIP: [IN] Setting fabricID BC5C01 on admin.
[1624995000232] [0x23fc09] CHIP: [IN] Since admin was modified, persisting changes to KVS
[1624995000232] [0x23fc09] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44250
[1624995000232] [0x23fc09] CHIP: [DMG] InvokeCommand =
[1624995000232] [0x23fc09] CHIP: [DMG] {
[1624995000232] [0x23fc09] CHIP: [DMG] 	CommandList =
[1624995000232] [0x23fc09] CHIP: [DMG] 	[
[1624995000232] [0x23fc09] CHIP: [DMG] 		CommandDataElement =
[1624995000232] [0x23fc09] CHIP: [DMG] 		{
[1624995000232] [0x23fc09] CHIP: [DMG] 			CommandPath =
[1624995000232] [0x23fc09] CHIP: [DMG] 			{
[1624995000232] [0x23fc09] CHIP: [DMG] 				EndpointId = 0x0,
[1624995000232] [0x23fc09] CHIP: [DMG] 				ClusterId = 0x3e,
[1624995000232] [0x23fc09] CHIP: [DMG] 				CommandId = 0xa1,
[1624995000232] [0x23fc09] CHIP: [DMG] 			},
[1624995000232] [0x23fc09] CHIP: [DMG]
[1624995000232] [0x23fc09] CHIP: [DMG] 			StatusElement =
[1624995000232] [0x23fc09] CHIP: [DMG] 			{
[1624995000232] [0x23fc09] CHIP: [DMG] 				GeneralCode = 0x0,
[1624995000232] [0x23fc09] CHIP: [DMG] 				ProtocolId = 0x5,
[1624995000232] [0x23fc09] CHIP: [DMG] 				protocolCode = 0x0,
[1624995000232] [0x23fc09] CHIP: [DMG] 			},
[1624995000232] [0x23fc09] CHIP: [DMG]
[1624995000232] [0x23fc09] CHIP: [DMG] 		},
[1624995000232] [0x23fc09] CHIP: [DMG]
[1624995000232] [0x23fc09] CHIP: [DMG] 	],
[1624995000232] [0x23fc09] CHIP: [DMG]
[1624995000232] [0x23fc09] CHIP: [DMG] }
[1624995000232] [0x23fc09] CHIP: [ZCL] DefaultResponse:
[1624995000232] [0x23fc09] CHIP: [ZCL]   Transaction: 0x1098e0488
[1624995000232] [0x23fc09] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624995000232] [0x23fc09] CHIP: [CTL] Device confirmed that it has received the root certificate
[1624995000232] [0x23fc09] CHIP: [CTL] Sending OpCSR request to 0x7ffee64f1f30 device
[1624995000232] [0x23fc09] CHIP: [DMG] ICR moving to [Initialize]
[1624995000232] [0x23fc09] CHIP: [DMG] ICR moving to [AddCommand]
[1624995000232] [0x23fc09] CHIP: [IN] Secure message was encrypted: Msg ID 1
[1624995000232] [0x23fc09] CHIP: [IN] Encrypted message 0x70000bcdf880 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44251.
[1624995000232] [0x23fc09] CHIP: [IN] Sending msg 0x70000bcdf880 to 0x0000000000BC5C01 at utc time: 332740808 msec
[1624995000232] [0x23fc09] CHIP: [IN] Sending secure msg on generic transport
[1624995000232] [0x23fc09] CHIP: [IN] Secure msg send status No Error
[1624995000232] [0x23fc09] CHIP: [DMG] ICR moving to [   Sending]
[1624995000232] [0x23fc09] CHIP: [CTL] Sent OpCSR request, waiting for the CSR
[1624995000232] [0x23fc09] CHIP: [DMG] ICR moving to [Uninitiali]
[1624995000892] [0x23fc08] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 3
[1624995000892] [0x23fc08] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44251
[1624995000892] [0x23fc08] CHIP: [DMG] InvokeCommand =
[1624995000892] [0x23fc08] CHIP: [DMG] {
[1624995000892] [0x23fc08] CHIP: [DMG] 	CommandList =
[1624995000892] [0x23fc08] CHIP: [DMG] 	[
[1624995000892] [0x23fc08] CHIP: [DMG] 		CommandDataElement =
[1624995000892] [0x23fc08] CHIP: [DMG] 		{
[1624995000892] [0x23fc08] CHIP: [DMG] 			CommandPath =
[1624995000892] [0x23fc08] CHIP: [DMG] 			{
[1624995000892] [0x23fc08] CHIP: [DMG] 				EndpointId = 0x0,
[1624995000892] [0x23fc08] CHIP: [DMG] 				ClusterId = 0x3e,
[1624995000892] [0x23fc08] CHIP: [DMG] 				CommandId = 0x5,
[1624995000892] [0x23fc08] CHIP: [DMG] 			},
[1624995000892] [0x23fc08] CHIP: [DMG]
[1624995000892] [0x23fc08] CHIP: [DMG] 			CommandData =
[1624995000892] [0x23fc08] CHIP: [DMG] 			{
[1624995000892] [0x23fc08] CHIP: [DMG] 				0x0 = [
[1624995000892] [0x23fc08] CHIP: [DMG] 					0x30, 0x81, 0xc8, 0x30, 0x70, 0x2, 0x1, 0x0, 0x30, 0xe, 0x31, 0xc, 0x30, 0xa, 0x6, 0x3, 0x55, 0x4, 0xa, 0xc, 0x3, 0x43, 0x53, 0x52, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6,
[1624995000892] [0x23fc08] CHIP: [DMG] 			]
[1624995000892] [0x23fc08] CHIP: [DMG] 				0x1 = [
[1624995000892] [0x23fc08] CHIP: [DMG] 					0x29, 0x39, 0xfa, 0x66, 0x93, 0x34, 0x99, 0x3b, 0xf2, 0xa9, 0x4f, 0x71, 0xaa, 0xc3, 0x11, 0xba, 0xa0, 0x92, 0x2f, 0x68, 0x8, 0xc0, 0x91, 0xf5, 0xc5, 0x8d, 0xa7, 0xc2, 0x45, 0xd8, 0x41, 0xa1,
[1624995000892] [0x23fc08] CHIP: [DMG] 			]
[1624995000892] [0x23fc08] CHIP: [DMG] 				0x2 = [
[1624995000892] [0x23fc08] CHIP: [DMG]
[1624995000892] [0x23fc08] CHIP: [DMG] 			]
[1624995000892] [0x23fc08] CHIP: [DMG] 				0x3 = [
[1624995000892] [0x23fc08] CHIP: [DMG]
[1624995000892] [0x23fc08] CHIP: [DMG] 			]
[1624995000892] [0x23fc08] CHIP: [DMG] 				0x4 = [
[1624995000892] [0x23fc08] CHIP: [DMG]
[1624995000892] [0x23fc08] CHIP: [DMG] 			]
[1624995000892] [0x23fc08] CHIP: [DMG] 				0x5 = [
[1624995000892] [0x23fc08] CHIP: [DMG]
[1624995000892] [0x23fc08] CHIP: [DMG] 			]
[1624995000892] [0x23fc08] CHIP: [DMG] 			},
[1624995000892] [0x23fc08] CHIP: [DMG] 		},
[1624995000892] [0x23fc08] CHIP: [DMG]
[1624995000892] [0x23fc08] CHIP: [DMG] 	],
[1624995000892] [0x23fc08] CHIP: [DMG]
[1624995000892] [0x23fc08] CHIP: [DMG] }
[1624995000892] [0x23fc08] CHIP: [ZCL] Received Cluster Command: Cluster=3e Command=5 Endpoint=0
[1624995000892] [0x23fc08] CHIP: [ZCL] OpCSRResponse:
[1624995000892] [0x23fc08] CHIP: [ZCL]   CSR: 203
[1624995000892] [0x23fc08] CHIP: [ZCL]   CSRNonce: 32
[1624995000892] [0x23fc08] CHIP: [ZCL]   VendorReserved1: 0
[1624995000892] [0x23fc08] CHIP: [ZCL]   VendorReserved2: 0
[1624995000892] [0x23fc08] CHIP: [ZCL]   VendorReserved3: 0
[1624995000892] [0x23fc08] CHIP: [ZCL]   Signature: 0
[1624995000892] [0x23fc08] CHIP: [CTL] Received certificate signing request from the device
[1624995000892] [0x23fc08] CHIP: [CTL] Getting intermediate CA certificate from the issuer
[1624995000892] [0x23fc08] CHIP: [CTL] GetIntermediateCACertificate returned 4190
[1624995000892] [0x23fc08] CHIP: [CTL] Intermediate CA is not needed
[1624995000892] [0x23fc08] CHIP: [CTL] Sending operational certificate to the device
[1624995000892] [0x23fc08] CHIP: [DMG] ICR moving to [Initialize]
[1624995000892] [0x23fc08] CHIP: [DMG] ICR moving to [AddCommand]
[1624995000893] [0x23fc08] CHIP: [IN] Secure message was encrypted: Msg ID 2
[1624995000893] [0x23fc08] CHIP: [IN] Encrypted message 0x70000bc5c140 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44252.
[1624995000893] [0x23fc08] CHIP: [IN] Sending msg 0x70000bc5c140 to 0x0000000000BC5C01 at utc time: 332741468 msec
[1624995000893] [0x23fc08] CHIP: [IN] Sending secure msg on generic transport
[1624995000893] [0x23fc08] CHIP: [IN] Secure msg send status No Error
[1624995000893] [0x23fc08] CHIP: [DMG] ICR moving to [   Sending]
[1624995000893] [0x23fc08] CHIP: [CTL] Sent operational certificate to the device
[1624995000893] [0x23fc08] CHIP: [DMG] ICR moving to [Uninitiali]
[1624995001162] [0x23fc09] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 3
[1624995001162] [0x23fc09] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44252
[1624995001162] [0x23fc09] CHIP: [DMG] InvokeCommand =
[1624995001162] [0x23fc09] CHIP: [DMG] {
[1624995001162] [0x23fc09] CHIP: [DMG] 	CommandList =
[1624995001162] [0x23fc09] CHIP: [DMG] 	[
[1624995001162] [0x23fc09] CHIP: [DMG] 		CommandDataElement =
[1624995001162] [0x23fc09] CHIP: [DMG] 		{
[1624995001162] [0x23fc09] CHIP: [DMG] 			CommandPath =
[1624995001162] [0x23fc09] CHIP: [DMG] 			{
[1624995001162] [0x23fc09] CHIP: [DMG] 				EndpointId = 0x0,
[1624995001162] [0x23fc09] CHIP: [DMG] 				ClusterId = 0x3e,
[1624995001162] [0x23fc09] CHIP: [DMG] 				CommandId = 0x6,
[1624995001162] [0x23fc09] CHIP: [DMG] 			},
[1624995001162] [0x23fc09] CHIP: [DMG]
[1624995001162] [0x23fc09] CHIP: [DMG] 			StatusElement =
[1624995001162] [0x23fc09] CHIP: [DMG] 			{
[1624995001162] [0x23fc09] CHIP: [DMG] 				GeneralCode = 0x0,
[1624995001162] [0x23fc09] CHIP: [DMG] 				ProtocolId = 0x5,
[1624995001162] [0x23fc09] CHIP: [DMG] 				protocolCode = 0x0,
[1624995001162] [0x23fc09] CHIP: [DMG] 			},
[1624995001162] [0x23fc09] CHIP: [DMG]
[1624995001162] [0x23fc09] CHIP: [DMG] 		},
[1624995001162] [0x23fc09] CHIP: [DMG]
[1624995001162] [0x23fc09] CHIP: [DMG] 	],
[1624995001162] [0x23fc09] CHIP: [DMG]
[1624995001162] [0x23fc09] CHIP: [DMG] }
[1624995001162] [0x23fc09] CHIP: [ZCL] DefaultResponse:
[1624995001162] [0x23fc09] CHIP: [ZCL]   Transaction: 0x1098e0488
[1624995001162] [0x23fc09] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624995001162] [0x23fc09] CHIP: [CTL] Device confirmed that it has received the operational certificate
[1624995001162] [0x23fc09] CHIP: [CTL] Operational credentials provisioned on device 0x7ffee64f1f30
[1624995001163] [0x23fc09] CHIP: [TOO] Secure Pairing Success
[1624995001163] [0x23fc09] CHIP: [TOO] Pairing Success
[1624995001163] [0x23fc09] CHIP: [DMG] ICR moving to [Initialize]
[1624995001163] [0x23fc09] CHIP: [DMG] ICR moving to [AddCommand]
[1624995001163] [0x23fc09] CHIP: [IN] Connection from 'BLE' expired
[1624995001163] [0x23fc09] CHIP: [CTL] OnConnectionExpired was called for unknown device, ignoring it.
[1624995001163] [0x23fc09] CHIP: [IN] New pairing for device 0x0000000000bc5c01, key 0!!
[1624995001163] [0x23fc09] CHIP: [IN] Secure message was encrypted: Msg ID 4
[1624995001163] [0x23fc09] CHIP: [IN] Encrypted message 0x70000bcdf750 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44253.
[1624995001163] [0x23fc09] CHIP: [IN] Sending msg 0x70000bcdf750 to 0x0000000000BC5C01 at utc time: 332741739 msec
[1624995001163] [0x23fc09] CHIP: [IN] Sending secure msg on generic transport
[1624995001163] [0x23fc09] CHIP: [IN] Secure msg send status No Error
[1624995001163] [0x23fc09] CHIP: [DMG] ICR moving to [   Sending]
[1624995001163] [0x23fc09] CHIP: [DMG] ICR moving to [Uninitiali]
[1624995001372] [0x23fc09] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 3
[1624995001372] [0x23fc09] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44253
[1624995001372] [0x23fc09] CHIP: [DMG] InvokeCommand =
[1624995001372] [0x23fc09] CHIP: [DMG] {
[1624995001372] [0x23fc09] CHIP: [DMG] 	CommandList =
[1624995001372] [0x23fc09] CHIP: [DMG] 	[
[1624995001372] [0x23fc09] CHIP: [DMG] 		CommandDataElement =
[1624995001372] [0x23fc09] CHIP: [DMG] 		{
[1624995001372] [0x23fc09] CHIP: [DMG] 			CommandPath =
[1624995001372] [0x23fc09] CHIP: [DMG] 			{
[1624995001372] [0x23fc09] CHIP: [DMG] 				EndpointId = 0x0,
[1624995001372] [0x23fc09] CHIP: [DMG] 				ClusterId = 0x31,
[1624995001372] [0x23fc09] CHIP: [DMG] 				CommandId = 0x2,
[1624995001372] [0x23fc09] CHIP: [DMG] 			},
[1624995001372] [0x23fc09] CHIP: [DMG]
[1624995001372] [0x23fc09] CHIP: [DMG] 			StatusElement =
[1624995001372] [0x23fc09] CHIP: [DMG] 			{
[1624995001372] [0x23fc09] CHIP: [DMG] 				GeneralCode = 0x0,
[1624995001372] [0x23fc09] CHIP: [DMG] 				ProtocolId = 0x5,
[1624995001372] [0x23fc09] CHIP: [DMG] 				protocolCode = 0x0,
[1624995001372] [0x23fc09] CHIP: [DMG] 			},
[1624995001372] [0x23fc09] CHIP: [DMG]
[1624995001372] [0x23fc09] CHIP: [DMG] 		},
[1624995001372] [0x23fc09] CHIP: [DMG]
[1624995001372] [0x23fc09] CHIP: [DMG] 	],
[1624995001372] [0x23fc09] CHIP: [DMG]
[1624995001372] [0x23fc09] CHIP: [DMG] }
[1624995001372] [0x23fc09] CHIP: [ZCL] DefaultResponse:
[1624995001372] [0x23fc09] CHIP: [ZCL]   Transaction: 0x1098e0598
[1624995001372] [0x23fc09] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624995001372] [0x23fc09] CHIP: [TOO] AddNetworkResponse
[1624995001372] [0x23fc09] CHIP: [DMG] ICR moving to [Initialize]
[1624995001372] [0x23fc09] CHIP: [DMG] ICR moving to [AddCommand]
[1624995001372] [0x23fc09] CHIP: [IN] Secure message was encrypted: Msg ID 5
[1624995001372] [0x23fc09] CHIP: [IN] Encrypted message 0x70000bcdf890 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44254.
[1624995001372] [0x23fc09] CHIP: [IN] Sending msg 0x70000bcdf890 to 0x0000000000BC5C01 at utc time: 332741948 msec
[1624995001372] [0x23fc09] CHIP: [IN] Sending secure msg on generic transport
[1624995001372] [0x23fc09] CHIP: [IN] Secure msg send status No Error
[1624995001372] [0x23fc09] CHIP: [DMG] ICR moving to [   Sending]
[1624995001372] [0x23fc09] CHIP: [DMG] ICR moving to [Uninitiali]
[1624995001582] [0x23fc09] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 3
[1624995001582] [0x23fc09] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44254
[1624995001582] [0x23fc09] CHIP: [DMG] InvokeCommand =
[1624995001582] [0x23fc09] CHIP: [DMG] {
[1624995001582] [0x23fc09] CHIP: [DMG] 	CommandList =
[1624995001582] [0x23fc09] CHIP: [DMG] 	[
[1624995001582] [0x23fc09] CHIP: [DMG] 		CommandDataElement =
[1624995001582] [0x23fc09] CHIP: [DMG] 		{
[1624995001582] [0x23fc09] CHIP: [DMG] 			CommandPath =
[1624995001582] [0x23fc09] CHIP: [DMG] 			{
[1624995001582] [0x23fc09] CHIP: [DMG] 				EndpointId = 0x0,
[1624995001582] [0x23fc09] CHIP: [DMG] 				ClusterId = 0x31,
[1624995001582] [0x23fc09] CHIP: [DMG] 				CommandId = 0xc,
[1624995001582] [0x23fc09] CHIP: [DMG] 			},
[1624995001582] [0x23fc09] CHIP: [DMG]
[1624995001582] [0x23fc09] CHIP: [DMG] 			StatusElement =
[1624995001582] [0x23fc09] CHIP: [DMG] 			{
[1624995001582] [0x23fc09] CHIP: [DMG] 				GeneralCode = 0x1,
[1624995001582] [0x23fc09] CHIP: [DMG] 				ProtocolId = 0x5,
[1624995001582] [0x23fc09] CHIP: [DMG] 				protocolCode = 0x1,
[1624995001582] [0x23fc09] CHIP: [DMG] 			},
[1624995001582] [0x23fc09] CHIP: [DMG]
[1624995001582] [0x23fc09] CHIP: [DMG] 		},
[1624995001582] [0x23fc09] CHIP: [DMG]
[1624995001582] [0x23fc09] CHIP: [DMG] 	],
[1624995001582] [0x23fc09] CHIP: [DMG]
[1624995001582] [0x23fc09] CHIP: [DMG] }
[1624995001582] [0x23fc09] CHIP: [ZCL] DefaultResponse:
[1624995001582] [0x23fc09] CHIP: [ZCL]   Transaction: 0x1098e0488
[1624995001582] [0x23fc09] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_FAILURE (0x01)
[1624995001582] [0x23fc09] CHIP: [TOO] Default Failure Response: 0x01
[1624995001582] [0x23fc09] CHIP: [DMG] ICR moving to [Uninitiali]
[1624995001582] [0x23fc04] CHIP: [TOO] Run command failure: CHIP Error 4172 (0x0000104C): Internal error
[1624995001582] [0x23fc04] CHIP: [CTL] Shutting down the commissioner
[1624995001582] [0x23fc04] CHIP: [CTL] Shutting down the controller
[1624995001582] [0x23fc04] CHIP: [DL] Inet Layer shutdown
[1624995001582] [0x23fc04] CHIP: [DL] BLE layer shutdown
[1624995001582] [0x23fc04] CHIP: [IN] Clearing BLE pending packets.
[1624995001583] [0x23fc04] CHIP: [BLE] Auto-closing end point's BLE connection.
[1624995001583] [0x23fc04] CHIP: [DL] System Layer shutdown
chaitanyajandhyala@chaitanyas-Mac-mini-2 chip-tool %
Device Side Log
$ sudo ./out/lighting-app/chip-lighting-app --wifi
[1624994976.062264][28953] CHIP:DL: Device Configuration:
[1624994976.062320][28953] CHIP:DL:   Serial Number: TEST_SN
[1624994976.062339][28953] CHIP:DL:   Vendor Id: 9050 (0x235A)
[1624994976.062357][28953] CHIP:DL:   Product Id: 65279 (0xFEFF)
[1624994976.062377][28953] CHIP:DL:   Product Revision: 1
[1624994976.062396][28953] CHIP:DL:   Setup Pin Code: 20202021
[1624994976.062415][28953] CHIP:DL:   Setup Discriminator: 3840 (0xF00)
[1624994976.062434][28953] CHIP:DL:   Manufacturing Date: (not set)
[1624994976.062451][28953] CHIP:DL:   Device Type: 257 (0x101)
[1624994976.062501][28953] CHIP:SVR: SetupQRCode: [MT:YNJV7VSC00KA0648G00]
[1624994976.062526][28953] CHIP:SVR: Copy/paste the below URL in a browser to see the QR Code:
[1624994976.062543][28953] CHIP:SVR: https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3AYNJV7VSC00KA0648G00
[1624994976.062572][28953] CHIP:SVR: Manual pairing code: [34970112332]
[1624994976.063019][28953] CHIP:ZCL: Using ZAP configuration...
[1624994976.063136][28953] CHIP:ZCL: deactivate report event
[1624994976.063157][28953] CHIP:ZCL: OpCreds: Initiating OpCreds cluster by writing fabrics list from admin pairing table.
[1624994976.063172][28953] CHIP:DIS: Set the admin pairing table delegate
[1624994976.063186][28953] CHIP:ZCL: OpCreds: Call to writeAdminsIntoFabricsListAttribute
[1624994976.063203][28953] CHIP:ZCL: OpCreds: Stored 0 admins in fabrics list attribute.
[1624994976.063230][28953] CHIP:ZCL: Unknown cluster ID: 40
[1624994976.063247][28953] CHIP:ZCL: Unknown cluster ID: 40
[1624994976.063262][28953] CHIP:ZCL: Unknown cluster ID: 40
[1624994976.063277][28953] CHIP:ZCL: Unknown cluster ID: 40
[1624994976.063292][28953] CHIP:ZCL: Unknown cluster ID: 40
[1624994976.063314][28953] CHIP:ZCL: Unknown cluster ID: 40
[1624994976.063330][28953] CHIP:ZCL: Unknown cluster ID: 40
[1624994976.063345][28953] CHIP:ZCL: Unknown cluster ID: 40
[1624994976.063533][28953] CHIP:DIS: Init admin pairing table with server storage
[1624994976.063716][28953] CHIP:IN: TransportMgr initialized
[1624994976.063949][28953] CHIP:DL: writing settings to file (/tmp/chip_counters.ini.tmp)
[1624994976.064511][28953] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1624994976.064563][28953] CHIP:DL: NVS set: chip-counters/GlobalMCTR = 7000 (0x1B58)
[1624994976.064582][28953] CHIP:IN: local node id is 0x0000000000BC5C01
[1624994976.064629][28953] CHIP:DL: wpa_supplicant: _IsWiFiStationProvisioned: interface not connected
[1624994976.064711][28953] CHIP:SC: Assigned local session key ID 0
[1624994976.064736][28953] CHIP:SC: Waiting for PBKDF param request
[1624994976.064756][28953] CHIP:DIS: Start dns-sd server
[1624994976.066596][28953] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: Inet Error 1016 (0x000003F8): Address not found
[1624994976.067163][28956] CHIP:DL: wpa_supplicant: connected to wpa_supplicant proxy
[1624994976.068540][28953] CHIP:DIS: CHIP minimal mDNS started advertising.
[1624994976.068728][28956] CHIP:DL: wpa_supplicant: WiFi interface: /fi/w1/wpa_supplicant1/Interfaces/0
[1624994976.068990][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624994976.069143][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624994976.069230][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624994976.069314][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624994976.069399][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624994976.069480][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624994976.069561][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624994976.069646][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624994976.069673][28953] CHIP:DL: wpa_supplicant: _IsWiFiStationProvisioned: interface not connected
[1624994976.070050][28953] CHIP:DIS: Using wifi MAC for hostname
[1624994976.070111][28953] CHIP:DL: rotatingDeviceId: 00007C5F6E176CD40F68685D100A1CF8A98B
[1624994976.070133][28953] CHIP:DL: wpa_supplicant: _IsWiFiStationProvisioned: interface not connected
[1624994976.070160][28953] CHIP:DIS: Advertise commission parameter vendorID=9050 productID=65279 discriminator=3840/00
[1624994976.070228][28953] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'.
[1624994976.070255][28953] CHIP:SVR: Server Listening...
[1624994976.070553][28959] CHIP:DL: TRACE: Bluez mainloop starting Thread
[1624994976.071226][28956] CHIP:DL: TRACE: Bus acquired for name MATTER-3840
[1624994976.071479][28956] CHIP:DL: CREATE service object at /chipoble/7119/service
[1624994976.072405][28956] CHIP:DL: Create characteristic object at /chipoble/7119/service/c1
[1624994976.072953][28956] CHIP:DL: Create characteristic object at /chipoble/7119/service/c2
[1624994976.073449][28956] CHIP:DL: CHIP BTP C1 /chipoble/7119/service
[1624994976.073483][28956] CHIP:DL: CHIP BTP C2 /chipoble/7119/service
[1624994976.073500][28956] CHIP:DL: CHIP_ENABLE_ADDITIONAL_DATA_ADVERTISING is TRUE
[1624994976.073525][28956] CHIP:DL: Create characteristic object at /chipoble/7119/service/c3
[1624994976.073955][28956] CHIP:DL: rotatingDeviceId: 00007C5F6E176CD40F68685D100A1CF8A98B
[1624994976.074050][28956] CHIP:DL: CHIP BTP C3 /chipoble/7119/service
[1624994976.080424][28953] CHIP:DL: PlatformBlueZInit init success
[1624994976.086570][28956] CHIP:DL: wpa_supplicant: connected to wpa_supplicant interface proxy
[1624994976.088743][28956] CHIP:DL: BluezPeripheralRegisterAppDone done
[1624994976.088819][28953] CHIP:DL: HandlePlatformSpecificBLEEvent 16392
[1624994976.088889][28956] CHIP:DL: Create adv object at /chipoble/7119/advertising
[1624994976.089313][28956] CHIP:DL: SET service data to {'0xFFF6': <[byte 0x00, 0x00, 0x0f, 0x5a, 0x23, 0xff, 0xfe]>}
[1624994976.090030][28953] CHIP:DL: HandlePlatformSpecificBLEEvent 16393
[1624994976.090078][28953] CHIP:DL: CHIPoBLE advertising config complete
[1624994976.098050][28956] CHIP:DL: RegisterAdvertisement complete
[1624994976.098326][28953] CHIP:DL: HandlePlatformSpecificBLEEvent 16394
[1624994999.171327][28956] CHIP:DL: Device 14:7D:DA:8F:84:62 (Path: /org/bluez/hci0/dev_14_7D_DA_8F_84_62) Connected
[1624994999.599760][28956] CHIP:DL: BluezCharacteristicAcquireWrite is called, conn: 0xffff94048e80
[1624994999.601806][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624994999.601980][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624994999.602309][28953] CHIP:BLE: local and remote recv window sizes = 3
[1624994999.602438][28953] CHIP:BLE: selected BTP version 3
[1624994999.602489][28953] CHIP:BLE: using BTP fragment sizes rx 128 / tx 20.
[1624994999.720294][28956] CHIP:DL: CHIPoBLE subscribe received
[1624994999.720530][28953] CHIP:IN: BLE EndPoint 0xaaaae9787550 Connection Complete
[1624994999.720617][28953] CHIP:DL: HandlePlatformSpecificBLEEvent 32777
[1624994999.720669][28953] CHIP:DL: Receive kCHIPoBLEConnectionEstablished
[1624994999.748856][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624994999.749517][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624994999.750079][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624994999.750302][28953] CHIP:EM: Received message of type 32 and protocolId 0 on exchange 44249
[1624994999.750382][28953] CHIP:EM: ec id: 44249, Delegate: 0x0xaaaae97895f0
[1624994999.750440][28953] CHIP:SC: Received PBKDF param request
[1624994999.752852][28953] CHIP:SC: Sent PBKDF param response
[1624994999.779135][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624994999.808943][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624994999.809543][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624994999.809756][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624994999.838906][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624994999.868785][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624994999.868984][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624994999.869279][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624994999.899011][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624994999.899923][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624994999.900457][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624994999.900694][28953] CHIP:EM: Received message of type 34 and protocolId 0 on exchange 44249
[1624994999.900760][28953] CHIP:SC: Received spake2p msg1
[1624994999.902233][28953] CHIP:SC: Peer assigned session key ID 3
[1624994999.904246][28953] CHIP:SC: Sent spake2p msg2
[1624994999.929268][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624994999.958792][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624994999.959442][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624994999.959744][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624994999.989245][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.018858][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.019169][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.019368][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.049023][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.078899][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.079113][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.079302][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.109275][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.109559][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.110261][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.110543][28953] CHIP:EM: Received message of type 36 and protocolId 0 on exchange 44249
[1624995000.110619][28953] CHIP:SC: Received spake2p msg3
[1624995000.110774][28953] CHIP:IN: New pairing for device 0x0000000000000000, key 3!!
[1624995000.110892][28953] CHIP:SVR: Device completed SPAKE2+ handshake
[1624995000.110969][28953] CHIP:SVR: Persisting admin ID 0, next available 1
[1624995000.115516][28953] CHIP:SVR: Stored value in server storage
[1624995000.116016][28953] CHIP:DL: writing settings to file (/tmp/chip_server_kvs.tmp)
[1624995000.116978][28953] CHIP:DL: renamed tmp file to file (/tmp/chip_server_kvs)
[1624995000.117053][28953] CHIP:DIS: Admin (0) persisted to storage. Calling OnAdminPersistedToStorage
[1624995000.117144][28953] CHIP:ZCL: OpCreds: Admin 0 was persisted to storage. FabricId<PHONE_NUMBER>0000000, NodeId 000000000DBD04AE0, VendorId 0xE96DD9E0
[1624995000.117197][28953] CHIP:ZCL: OpCreds: Call to writeAdminsIntoFabricsListAttribute
[1624995000.117242][28953] CHIP:ZCL: OpCreds: Skipping over unitialized admin with fabricId 0x0000000000000000, nodeId 0x0000000000000000 vendorId 0x0000
[1624995000.117291][28953] CHIP:ZCL: OpCreds: Stored 0 admins in fabrics list attribute.
[1624995000.117540][28953] CHIP:DL: writing settings to file (/tmp/chip_server_kvs.tmp)
[1624995000.118517][28953] CHIP:DL: renamed tmp file to file (/tmp/chip_server_kvs)
[1624995000.118587][28953] CHIP:SVR: Persisting admin ID successfully
[1624995000.118631][28953] CHIP:SVR: Device completed Rendezvous process
[1624995000.118679][28953] CHIP:SVR: Stored value in server storage
[1624995000.118899][28953] CHIP:DL: writing settings to file (/tmp/chip_server_kvs.tmp)
[1624995000.119660][28953] CHIP:DL: renamed tmp file to file (/tmp/chip_server_kvs)
[1624995000.119697][28953] CHIP:SVR: Stored value in server storage
[1624995000.119808][28953] CHIP:DL: writing settings to file (/tmp/chip_server_kvs.tmp)
[1624995000.120507][28953] CHIP:DL: renamed tmp file to file (/tmp/chip_server_kvs)
[1624995000.122350][28956] CHIP:DL: UnregisterAdvertisement complete
[1624995000.122509][28953] CHIP:DL: HandlePlatformSpecificBLEEvent 16395
[1624995000.122874][28953] CHIP:DL: CHIPoBLE advertising stopped
[1624995000.139865][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.140452][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.169157][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.170548][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.171639][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.199374][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.200249][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.200540][28953] CHIP:IN: Secure transport received message destined to fabric 0, node 0x0000000000BC5C01. Key ID 0
[1624995000.200672][28953] CHIP:IN: Setting nodeID BC5C01 on admin.
[1624995000.200715][28953] CHIP:IN: Setting fabricID 1B669 on admin.
[1624995000.200751][28953] CHIP:IN: Since admin was modified, persisting changes to KVS
[1624995000.201405][28953] CHIP:SVR: Stored value in server storage
[1624995000.201801][28953] CHIP:DL: writing settings to file (/tmp/chip_server_kvs.tmp)
[1624995000.202804][28953] CHIP:DL: renamed tmp file to file (/tmp/chip_server_kvs)
[1624995000.202878][28953] CHIP:DIS: Admin (0) persisted to storage. Calling OnAdminPersistedToStorage
[1624995000.202921][28953] CHIP:ZCL: OpCreds: Admin 0 was persisted to storage. FabricId 00001B66900000000, NodeId bc5c0100000000DBD04EA0, VendorId 0xE96DD9E0
[1624995000.202965][28953] CHIP:ZCL: OpCreds: Call to writeAdminsIntoFabricsListAttribute
[1624995000.203004][28953] CHIP:ZCL: OpCreds: Skipping over unitialized admin with fabricId 0x000000000001B669, nodeId 0x0000000000BC5C01 vendorId 0x0000
[1624995000.203046][28953] CHIP:ZCL: OpCreds: Stored 0 admins in fabrics list attribute.
[1624995000.203094][28953] CHIP:EM: Received message of type 8 and protocolId 5 on exchange 44250
[1624995000.203145][28953] CHIP:EM: ec id: 44250, Delegate: 0x0xaaaae978b7d0
[1624995000.203209][28953] CHIP:DMG: ICR moving to [Initialize]
[1624995000.203262][28953] CHIP:DMG: InvokeCommand =
[1624995000.203303][28953] CHIP:DMG: {
[1624995000.203339][28953] CHIP:DMG: 	CommandList =
[1624995000.203383][28953] CHIP:DMG: 	[
[1624995000.203425][28953] CHIP:DMG: 		CommandDataElement =
[1624995000.203505][28953] CHIP:DMG: 		{
[1624995000.203562][28953] CHIP:DMG: 			CommandPath =
[1624995000.203618][28953] CHIP:DMG: 			{
[1624995000.203671][28953] CHIP:DMG: 				EndpointId = 0x0,
[1624995000.203718][28953] CHIP:DMG: 				ClusterId = 0x3e,
[1624995000.203764][28953] CHIP:DMG: 				CommandId = 0xa1,
[1624995000.203809][28953] CHIP:DMG: 			},
[1624995000.203867][28953] CHIP:DMG:
[1624995000.203915][28953] CHIP:DMG: 			CommandData =
[1624995000.203983][28953] CHIP:DMG: 			{
[1624995000.204049][28953] CHIP:DMG: 				0x0 = [
[1624995000.204145][28953] CHIP:DMG: 					0xd5, 0x0, 0x0, 0x8, 0x0, 0x1, 0x0, 0x30, 0x1, 0x1, 0x0, 0x24, 0x2, 0x1, 0x37, 0x3, 0x24, 0x14, 0x0, 0x24, 0x15, 0x0, 0x18, 0x26, 0x4, 0x80, 0x22, 0x81, 0x27, 0x26, 0x5, 0x80, 0x25, 0x4d, 0x3a, 0x37, 0x6, 0x24, 0x14, 0x0, 0x24, 0x15, 0x0, 0x18, 0x24,
[1624995000.204217][28953] CHIP:DMG: 			]
[1624995000.204274][28953] CHIP:DMG: 			},
[1624995000.204323][28953] CHIP:DMG: 		},
[1624995000.204376][28953] CHIP:DMG:
[1624995000.204418][28953] CHIP:DMG: 	],
[1624995000.204476][28953] CHIP:DMG:
[1624995000.204515][28953] CHIP:DMG: }
[1624995000.204572][28953] CHIP:ZCL: Received Cluster Command: Cluster=3e Command=a1 Endpoint=0
[1624995000.204611][28953] CHIP:ZCL: OpCreds: commissioner has added a trusted root Cert
[1624995000.204648][28953] CHIP:ZCL: OpCreds: Finding admin with fabricId 0x000000000001B669.
[1624995000.204686][28953] CHIP:DIS: Checking ind:0 [fabricId 0x000000000001B669 nodeId 0x0000000000BC5C01 vendorId 0] vs [fabricId 0x000000000001B669 nodeId 0x0000000000000000 vendorId 0]
[1624995000.204730][28953] CHIP:DIS: Found a match!
[1624995000.205393][28953] CHIP:SVR: Stored value in server storage
[1624995000.205742][28953] CHIP:DL: writing settings to file (/tmp/chip_server_kvs.tmp)
[1624995000.206544][28953] CHIP:DL: renamed tmp file to file (/tmp/chip_server_kvs)
[1624995000.206606][28953] CHIP:DIS: Admin (0) persisted to storage. Calling OnAdminPersistedToStorage
[1624995000.206649][28953] CHIP:ZCL: OpCreds: Admin 0 was persisted to storage. FabricId 00001B66900000000, NodeId bc5c0100000000DBD04790, VendorId 0xE96DD9E0
[1624995000.206693][28953] CHIP:ZCL: OpCreds: Call to writeAdminsIntoFabricsListAttribute
[1624995000.206730][28953] CHIP:ZCL: OpCreds: Skipping over unitialized admin with fabricId 0x000000000001B669, nodeId 0x0000000000BC5C01 vendorId 0x0000
[1624995000.206772][28953] CHIP:ZCL: OpCreds: Stored 0 admins in fabrics list attribute.
[1624995000.206832][28953] CHIP:DMG: ICR moving to [AddCommand]
[1624995000.206956][28953] CHIP:IN: Secure message was encrypted: Msg ID 1
[1624995000.207006][28953] CHIP:IN: Encrypted message 0xffffdbd04ad0 from 0x0000000000BC5C01 to 0x000000000001B669 of type 9 and protocolId 5 on exchange 44250.
[1624995000.207056][28953] CHIP:IN: Sending msg 0xffffdbd04ad0 to 0x000000000001B669 at utc time: 508479721 msec
[1624995000.207095][28953] CHIP:IN: Sending secure msg on generic transport
[1624995000.207137][28953] CHIP:IN: Secure msg send status No Error
[1624995000.207175][28953] CHIP:DMG: ICR moving to [   Sending]
[1624995000.207217][28953] CHIP:DMG: ICR moving to [Uninitiali]
[1624995000.229576][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.258860][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.259327][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.259545][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.288974][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.318861][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.319075][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.319688][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.349453][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.378859][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.379156][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.379376][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.409903][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.410457][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.410791][28953] CHIP:IN: Secure transport received message destined to fabric 0, node 0x0000000000BC5C01. Key ID 0
[1624995000.410917][28953] CHIP:EM: Received message of type 8 and protocolId 5 on exchange 44251
[1624995000.410984][28953] CHIP:EM: ec id: 44251, Delegate: 0x0xaaaae978b7d0
[1624995000.411052][28953] CHIP:DMG: ICR moving to [Initialize]
[1624995000.411113][28953] CHIP:DMG: InvokeCommand =
[1624995000.411160][28953] CHIP:DMG: {
[1624995000.411202][28953] CHIP:DMG: 	CommandList =
[1624995000.411253][28953] CHIP:DMG: 	[
[1624995000.411302][28953] CHIP:DMG: 		CommandDataElement =
[1624995000.411400][28953] CHIP:DMG: 		{
[1624995000.411468][28953] CHIP:DMG: 			CommandPath =
[1624995000.411566][28953] CHIP:DMG: 			{
[1624995000.411669][28953] CHIP:DMG: 				EndpointId = 0x0,
[1624995000.411848][28953] CHIP:DMG: 				ClusterId = 0x3e,
[1624995000.412451][28953] CHIP:DMG: 				CommandId = 0x4,
[1624995000.412574][28953] CHIP:DMG: 			},
[1624995000.412679][28953] CHIP:DMG:
[1624995000.412746][28953] CHIP:DMG: 			CommandData =
[1624995000.412839][28953] CHIP:DMG: 			{
[1624995000.412953][28953] CHIP:DMG: 				0x0 = [
[1624995000.413128][28953] CHIP:DMG: 					0x29, 0x39, 0xfa, 0x66, 0x93, 0x34, 0x99, 0x3b, 0xf2, 0xa9, 0x4f, 0x71, 0xaa, 0xc3, 0x11, 0xba, 0xa0, 0x92, 0x2f, 0x68, 0x8, 0xc0, 0x91, 0xf5, 0xc5, 0x8d, 0xa7, 0xc2, 0x45, 0xd8, 0x41, 0xa1,
[1624995000.413241][28953] CHIP:DMG: 			]
[1624995000.413342][28953] CHIP:DMG: 			},
[1624995000.413438][28953] CHIP:DMG: 		},
[1624995000.413509][28953] CHIP:DMG:
[1624995000.413559][28953] CHIP:DMG: 	],
[1624995000.413616][28953] CHIP:DMG:
[1624995000.413661][28953] CHIP:DMG: }
[1624995000.413729][28953] CHIP:ZCL: Received Cluster Command: Cluster=3e Command=4 Endpoint=0
[1624995000.413783][28953] CHIP:ZCL: OpCreds: commissioner has requested an OpCSR
[1624995000.413828][28953] CHIP:ZCL: OpCreds: Finding admin with fabricId 0x000000000001B669.
[1624995000.413873][28953] CHIP:DIS: Checking ind:0 [fabricId 0x000000000001B669 nodeId 0x0000000000BC5C01 vendorId 0] vs [fabricId 0x000000000001B669 nodeId 0x0000000000000000 vendorId 0]
[1624995000.413925][28953] CHIP:DIS: Found a match!
[1624995000.415994][28953] CHIP:ZCL: OpCreds: NewCertificateSigningRequest returned 0
[1624995000.416084][28953] CHIP:DMG: ICR moving to [AddCommand]
[1624995000.416246][28953] CHIP:IN: Secure message was encrypted: Msg ID 2
[1624995000.416303][28953] CHIP:IN: Encrypted message 0xffffdbd04ad0 from 0x0000000000BC5C01 to 0x000000000001B669 of type 9 and protocolId 5 on exchange 44251.
[1624995000.416362][28953] CHIP:IN: Sending msg 0xffffdbd04ad0 to 0x000000000001B669 at utc time: 508479931 msec
[1624995000.416408][28953] CHIP:IN: Sending secure msg on generic transport
[1624995000.416454][28953] CHIP:IN: Secure msg send status No Error
[1624995000.416498][28953] CHIP:DMG: ICR moving to [   Sending]
[1624995000.416546][28953] CHIP:DMG: ICR moving to [Uninitiali]
[1624995000.439020][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.468914][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.469759][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.469975][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.499057][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.528880][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.529276][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.529846][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.559250][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.588966][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.589679][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.589896][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.619108][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.648930][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.649331][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.649580][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.694008][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.738893][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.739240][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.739519][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.768775][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.798782][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.798996][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.799531][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.829146][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.858836][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.859141][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.859335][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.888908][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.918909][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.919132][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.919965][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.949408][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995000.978904][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995000.979247][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995000.979474][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.008864][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.038733][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.038981][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.039134][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.070154][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.070899][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.098912][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.100518][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.101665][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.129669][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.130482][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.130778][28953] CHIP:IN: Secure transport received message destined to fabric 0, node 0x0000000000BC5C01. Key ID 0
[1624995001.130917][28953] CHIP:EM: Received message of type 8 and protocolId 5 on exchange 44252
[1624995001.130975][28953] CHIP:EM: ec id: 44252, Delegate: 0x0xaaaae978b7d0
[1624995001.131037][28953] CHIP:DMG: ICR moving to [Initialize]
[1624995001.131091][28953] CHIP:DMG: InvokeCommand =
[1624995001.131133][28953] CHIP:DMG: {
[1624995001.131170][28953] CHIP:DMG: 	CommandList =
[1624995001.131216][28953] CHIP:DMG: 	[
[1624995001.131274][28953] CHIP:DMG: 		CommandDataElement =
[1624995001.131326][28953] CHIP:DMG: 		{
[1624995001.131365][28953] CHIP:DMG: 			CommandPath =
[1624995001.131409][28953] CHIP:DMG: 			{
[1624995001.131452][28953] CHIP:DMG: 				EndpointId = 0x0,
[1624995001.131499][28953] CHIP:DMG: 				ClusterId = 0x3e,
[1624995001.131546][28953] CHIP:DMG: 				CommandId = 0x6,
[1624995001.131589][28953] CHIP:DMG: 			},
[1624995001.131640][28953] CHIP:DMG:
[1624995001.131687][28953] CHIP:DMG: 			CommandData =
[1624995001.131731][28953] CHIP:DMG: 			{
[1624995001.131770][28953] CHIP:DMG: 				0x0 = [
[1624995001.131848][28953] CHIP:DMG: 					0x16, 0x15, 0x30, 0x1, 0x1, 0x1, 0x24, 0x2, 0x1, 0x37, 0x3, 0x24, 0x14, 0x0, 0x24, 0x15, 0x0, 0x18, 0x26, 0x4, 0x80, 0x22, 0x81, 0x27, 0x26, 0x5, 0x80, 0x25, 0x4d, 0x3a, 0x37, 0x6, 0x26, 0x11, 0x1, 0x5c, 0xbc, 0x0, 0x24, 0x15, 0x0, 0x18, 0x24, 0x7, 0
[1624995001.131912][28953] CHIP:DMG: 			]
[1624995001.131958][28953] CHIP:DMG: 				0x1 = [
[1624995001.132001][28953] CHIP:DMG:
[1624995001.132053][28953] CHIP:DMG: 			]
[1624995001.132101][28953] CHIP:DMG: 				0x2 = 112233,
[1624995001.132153][28953] CHIP:DMG: 				0x3 = 0,
[1624995001.132203][28953] CHIP:DMG: 			},
[1624995001.132245][28953] CHIP:DMG: 		},
[1624995001.132288][28953] CHIP:DMG:
[1624995001.132327][28953] CHIP:DMG: 	],
[1624995001.132369][28953] CHIP:DMG:
[1624995001.132402][28953] CHIP:DMG: }
[1624995001.132458][28953] CHIP:ZCL: Received Cluster Command: Cluster=3e Command=6 Endpoint=0
[1624995001.132505][28953] CHIP:ZCL: OpCreds: commissioner has added an Op Cert
[1624995001.132540][28953] CHIP:ZCL: OpCreds: Finding admin with fabricId 0x000000000001B669.
[1624995001.132575][28953] CHIP:DIS: Checking ind:0 [fabricId 0x000000000001B669 nodeId 0x0000000000BC5C01 vendorId 0] vs [fabricId 0x000000000001B669 nodeId 0x0000000000000000 vendorId 0]
[1624995001.132615][28953] CHIP:DIS: Found a match!
[1624995001.132674][28953] CHIP:SVR: Stored value in server storage
[1624995001.133029][28953] CHIP:DL: writing settings to file (/tmp/chip_server_kvs.tmp)
[1624995001.133965][28953] CHIP:DL: renamed tmp file to file (/tmp/chip_server_kvs)
[1624995001.134031][28953] CHIP:DIS: Admin (0) persisted to storage. Calling OnAdminPersistedToStorage
[1624995001.134068][28953] CHIP:ZCL: OpCreds: Admin 0 was persisted to storage. FabricId 00001B66900000000, NodeId bc5c0100000000DBD04770, VendorId 0xE96DD9E0
[1624995001.134108][28953] CHIP:ZCL: OpCreds: Call to writeAdminsIntoFabricsListAttribute
[1624995001.134142][28953] CHIP:ZCL: OpCreds: Skipping over unitialized admin with fabricId 0x000000000001B669, nodeId 0x0000000000BC5C01 vendorId 0x0000
[1624995001.134179][28953] CHIP:ZCL: OpCreds: Stored 0 admins in fabrics list attribute.
[1624995001.134232][28953] CHIP:DIS: Found admin pairing for admin 0, node 0x0000000000BC5C01
[1624995001.134919][28953] CHIP:DIS: Using wifi MAC for hostname
[1624995001.134965][28953] CHIP:DIS: Advertise operational node<PHONE_NUMBER>000000-0000000000BC5C01
[1624995001.135041][28953] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'.
[1624995001.135095][28953] CHIP:DMG: ICR moving to [AddCommand]
[1624995001.135212][28953] CHIP:IN: Secure message was encrypted: Msg ID 3
[1624995001.135256][28953] CHIP:IN: Encrypted message 0xffffdbd04ad0 from 0x0000000000BC5C01 to 0x000000000001B669 of type 9 and protocolId 5 on exchange 44252.
[1624995001.135301][28953] CHIP:IN: Sending msg 0xffffdbd04ad0 to 0x000000000001B669 at utc time: 508480650 msec
[1624995001.135337][28953] CHIP:IN: Sending secure msg on generic transport
[1624995001.135374][28953] CHIP:IN: Secure msg send status No Error
[1624995001.135407][28953] CHIP:DMG: ICR moving to [   Sending]
[1624995001.135442][28953] CHIP:DMG: ICR moving to [Uninitiali]
[1624995001.159297][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.188869][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.189398][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.189590][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.218946][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.248911][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.249214][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.249852][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.279134][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.308933][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.309244][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.309522][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.339973][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.340585][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.341012][28953] CHIP:IN: Secure transport received message destined to fabric 0, node 0x0000000000BC5C01. Key ID 0
[1624995001.341276][28953] CHIP:EM: Received message of type 8 and protocolId 5 on exchange 44253
[1624995001.341349][28953] CHIP:EM: ec id: 44253, Delegate: 0x0xaaaae978b7d0
[1624995001.341449][28953] CHIP:DMG: ICR moving to [Initialize]
[1624995001.341522][28953] CHIP:DMG: InvokeCommand =
[1624995001.341575][28953] CHIP:DMG: {
[1624995001.341640][28953] CHIP:DMG: 	CommandList =
[1624995001.341845][28953] CHIP:DMG: 	[
[1624995001.342003][28953] CHIP:DMG: 		CommandDataElement =
[1624995001.342335][28953] CHIP:DMG: 		{
[1624995001.342410][28953] CHIP:DMG: 			CommandPath =
[1624995001.342493][28953] CHIP:DMG: 			{
[1624995001.342553][28953] CHIP:DMG: 				EndpointId = 0x0,
[1624995001.342636][28953] CHIP:DMG: 				ClusterId = 0x31,
[1624995001.342708][28953] CHIP:DMG: 				CommandId = 0x2,
[1624995001.342777][28953] CHIP:DMG: 			},
[1624995001.342852][28953] CHIP:DMG:
[1624995001.342939][28953] CHIP:DMG: 			CommandData =
[1624995001.343019][28953] CHIP:DMG: 			{
[1624995001.343114][28953] CHIP:DMG: 				0x0 = [
[1624995001.343171][28953] CHIP:DMG: 					0x50, 0x61, 0x72, 0x74, 0x79, 0x67, 0x75, 0x79, 0x73,
[1624995001.343234][28953] CHIP:DMG: 			]
[1624995001.343323][28953] CHIP:DMG: 				0x1 = [
[1624995001.343373][28953] CHIP:DMG: 					0x49, 0x6e, 0x76, 0x61, 0x6c, 0x69, 0x64,
[1624995001.343422][28953] CHIP:DMG: 			]
[1624995001.343466][28953] CHIP:DMG: 				0x2 = 0,
[1624995001.343542][28953] CHIP:DMG: 				0x3 = 6000,
[1624995001.343599][28953] CHIP:DMG: 			},
[1624995001.343641][28953] CHIP:DMG: 		},
[1624995001.343695][28953] CHIP:DMG:
[1624995001.343726][28953] CHIP:DMG: 	],
[1624995001.343775][28953] CHIP:DMG:
[1624995001.343802][28953] CHIP:DMG: }
[1624995001.343858][28953] CHIP:ZCL: Received Cluster Command: Cluster=31 Command=2 Endpoint=0
[1624995001.343985][28953] CHIP:ZCL: WiFi provisioning data: SSID: Partyguys
[1624995001.344016][28953] CHIP:ZCL: AddWiFiNetwork: 0
[1624995001.344103][28953] CHIP:DMG: ICR moving to [AddCommand]
[1624995001.344249][28953] CHIP:IN: Secure message was encrypted: Msg ID 4
[1624995001.344299][28953] CHIP:IN: Encrypted message 0xffffdbd04ad0 from 0x0000000000BC5C01 to 0x000000000001B669 of type 9 and protocolId 5 on exchange 44253.
[1624995001.344338][28953] CHIP:IN: Sending msg 0xffffdbd04ad0 to 0x000000000001B669 at utc time: 508480859 msec
[1624995001.344418][28953] CHIP:IN: Sending secure msg on generic transport
[1624995001.344485][28953] CHIP:IN: Secure msg send status No Error
[1624995001.344527][28953] CHIP:DMG: ICR moving to [   Sending]
[1624995001.344557][28953] CHIP:DMG: ICR moving to [Uninitiali]
[1624995001.369148][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.398876][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.399493][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.399830][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.429113][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.458829][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.459022][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.459206][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.489166][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.519158][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.519398][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.519573][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.549897][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.550461][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.550795][28953] CHIP:IN: Secure transport received message destined to fabric 0, node 0x0000000000BC5C01. Key ID 0
[1624995001.550918][28953] CHIP:EM: Received message of type 8 and protocolId 5 on exchange 44254
[1624995001.550982][28953] CHIP:EM: ec id: 44254, Delegate: 0x0xaaaae978b7d0
[1624995001.551052][28953] CHIP:DMG: ICR moving to [Initialize]
[1624995001.551115][28953] CHIP:DMG: InvokeCommand =
[1624995001.551163][28953] CHIP:DMG: {
[1624995001.551205][28953] CHIP:DMG: 	CommandList =
[1624995001.551257][28953] CHIP:DMG: 	[
[1624995001.551306][28953] CHIP:DMG: 		CommandDataElement =
[1624995001.551372][28953] CHIP:DMG: 		{
[1624995001.551434][28953] CHIP:DMG: 			CommandPath =
[1624995001.551495][28953] CHIP:DMG: 			{
[1624995001.551560][28953] CHIP:DMG: 				EndpointId = 0x0,
[1624995001.551631][28953] CHIP:DMG: 				ClusterId = 0x31,
[1624995001.551697][28953] CHIP:DMG: 				CommandId = 0xc,
[1624995001.551767][28953] CHIP:DMG: 			},
[1624995001.551827][28953] CHIP:DMG:
[1624995001.551883][28953] CHIP:DMG: 			CommandData =
[1624995001.551935][28953] CHIP:DMG: 			{
[1624995001.551985][28953] CHIP:DMG: 				0x0 = [
[1624995001.552044][28953] CHIP:DMG: 					0x50, 0x61, 0x72, 0x74, 0x79, 0x67, 0x75, 0x79, 0x73,
[1624995001.552103][28953] CHIP:DMG: 			]
[1624995001.552155][28953] CHIP:DMG: 				0x1 = 0,
[1624995001.552210][28953] CHIP:DMG: 				0x2 = 6000,
[1624995001.552263][28953] CHIP:DMG: 			},
[1624995001.552310][28953] CHIP:DMG: 		},
[1624995001.552387][28953] CHIP:DMG:
[1624995001.552446][28953] CHIP:DMG: 	],
[1624995001.552510][28953] CHIP:DMG:
[1624995001.552557][28953] CHIP:DMG: }
[1624995001.552632][28953] CHIP:ZCL: Received Cluster Command: Cluster=31 Command=c Endpoint=0
[1624995001.552694][28953] CHIP:NP: LinuxNetworkProvisioningDelegate: SSID: Partyguys
[1624995001.558749][28953] CHIP:DL: wpa_supplicant: failed to add network: Partyguys: GDBus.Error:org.freedesktop.DBus.Error.InvalidArgs: invalid message format
[1624995001.558844][28953] CHIP:NP: Failed to connect to WiFi network: CHIP Error 4172 (0x0000104C): Internal error
[1624995001.558914][28953] CHIP:DMG: ICR moving to [AddCommand]
[1624995001.559090][28953] CHIP:IN: Secure message was encrypted: Msg ID 5
[1624995001.559151][28953] CHIP:IN: Encrypted message 0xffffdbd04ad0 from 0x0000000000BC5C01 to 0x000000000001B669 of type 9 and protocolId 5 on exchange 44254.
[1624995001.559213][28953] CHIP:IN: Sending msg 0xffffdbd04ad0 to 0x000000000001B669 at utc time: 508481074 msec
[1624995001.559259][28953] CHIP:IN: Sending secure msg on generic transport
[1624995001.559307][28953] CHIP:IN: Secure msg send status No Error
[1624995001.559352][28953] CHIP:DMG: ICR moving to [   Sending]
[1624995001.559400][28953] CHIP:DMG: ICR moving to [Uninitiali]
[1624995001.579283][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.608857][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.609507][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.609794][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.639435][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.668847][28956] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624995001.669052][28956] CHIP:BLE: Write request received debug 0xffff94048e80
[1624995001.669647][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.699182][28956] CHIP:BLE: Indication confirmation, 0xffff94048e80
[1624995001.805891][28956] CHIP:DL: Bluez disconnected
[1624995001.805967][28956] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1624995001.806382][28956] CHIP:BLE: Indication confirmation, (nil)
[1624995001.806530][28953] CHIP:IN: Clearing BLE pending packets.
[1624995001.806614][28953] CHIP:BLE: no endpoint for BLE sent data ack
[1624995003.953983][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995003.954102][28953] CHIP:DIS: Broadcasting mDns reply
[1624995016.901814][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995016.901876][28953] CHIP:DIS: Broadcasting mDns reply
[1624995027.018829][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995027.018888][28953] CHIP:DIS: Broadcasting mDns reply
[1624995036.045495][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995036.045558][28953] CHIP:DIS: Broadcasting mDns reply
[1624995066.695777][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995066.695835][28953] CHIP:DIS: Broadcasting mDns reply
[1624995085.810055][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995085.810122][28953] CHIP:DIS: Broadcasting mDns reply
[1624995101.751171][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995101.751234][28953] CHIP:DIS: Broadcasting mDns reply
[1624995114.024494][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995114.024561][28953] CHIP:DIS: Broadcasting mDns reply
[1624995115.703303][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995115.703366][28953] CHIP:DIS: Broadcasting mDns reply
[1624995140.530235][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995140.530298][28953] CHIP:DIS: Broadcasting mDns reply
[1624995154.411449][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995154.411514][28953] CHIP:DIS: Broadcasting mDns reply
[1624995234.732741][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995234.732810][28953] CHIP:DIS: Broadcasting mDns reply
[1624995252.969374][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995252.969440][28953] CHIP:DIS: Broadcasting mDns reply
[1624995279.920184][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995279.920246][28953] CHIP:DIS: Broadcasting mDns reply
[1624995350.157802][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995350.157866][28953] CHIP:DIS: Broadcasting mDns reply
[1624995364.408059][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995364.408120][28953] CHIP:DIS: Broadcasting mDns reply
[1624995412.138630][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995412.138696][28953] CHIP:DIS: Broadcasting mDns reply
[1624995429.132267][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995429.132329][28953] CHIP:DIS: Broadcasting mDns reply
[1624995459.421007][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995459.421084][28953] CHIP:DIS: Broadcasting mDns reply
[1624995486.669350][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995486.669416][28953] CHIP:DIS: Broadcasting mDns reply
[1624995505.236254][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995505.236322][28953] CHIP:DIS: Broadcasting mDns reply
[1624995515.372603][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995515.372673][28953] CHIP:DIS: Broadcasting mDns reply
[1624995521.336352][28953] CHIP:DIS: Replying to DNS-SD service listing request
[1624995521.336416][28953] CHIP:DIS: Broadcasting mDns reply

@cjandhyala  Thanks for update, I re-run my test with --wifi, and I can confirm #7806 did fix the BLE endpoint Full issue. With #7806, I can provision my RP4 successfully.

On MacPro side.

yufengs-mbp:host yufengw$ ./chip-tool pairing ble-wifi test-2g 12345678 12344321 20202021 3840
[1624996212353] [0x48e58e] CHIP: [DL] _Init
[1624996212353] [0x48e58e] CHIP: [IN] TransportMgr initialized
[1624996212353] [0x48e58e] CHIP: [DIS] Init admin pairing table with server storage
[1624996212353] [0x48e58e] CHIP: [IN] Loading certs from KVS
[1624996212353] [0x48e58e] CHIP: [IN] local node id is 0x000000000001B669
[1624996212354] [0x48e58e] CHIP: [ZCL] Using ZAP configuration...
[1624996212354] [0x48e58e] CHIP: [ZCL] deactivate report event
[1624996212354] [0x48e58e] CHIP: [CTL] Getting operational keys
[1624996212354] [0x48e58e] CHIP: [CTL] Generating credentials
[1624996212354] [0x48e58e] CHIP: [CTL] Loaded credentials successfully
[1624996212354] [0x48e5a4] CHIP: [BLE] NewConnection
[1624996212356] [0x48e5a4] CHIP: [SC] Assigned local session key ID 9
[1624996212356] [0x48e5a4] CHIP: [IN] Message appended to BLE send queue
[1624996212356] [0x48e5a4] CHIP: [SC] Sent PBKDF param request
[1624996212404] [0x48e5a6] CHIP: [BLE] CBManagerState: ON
[1624996217452] [0x48e5a4] CHIP: [BLE] Connecting to device with discriminator: 3840
[1624996230798] [0x48e69a] CHIP: [IN] BleConnectionComplete: endPoint 0x106c998e8
[1624996231652] [0x48e5a7] CHIP: [BLE] subscribe complete, ep = 0x106c998e8
[1624996231698] [0x48e69a] CHIP: [BLE] peripheral chose BTP version 3; central expected between 2 and 3
[1624996231698] [0x48e69a] CHIP: [BLE] using BTP fragment sizes rx 20 / tx 128.
[1624996231698] [0x48e69a] CHIP: [BLE] local and remote recv window size = 3
[1624996231698] [0x48e69a] CHIP: [IN] BLE EndPoint 0x106c998e8 Connection Complete
[1624996232418] [0x48e5a7] CHIP: [EM] Received message of type 33 and protocolId 0 on exchange 44249
[1624996232418] [0x48e5a7] CHIP: [SC] Received PBKDF param response
[1624996232419] [0x48e5a7] CHIP: [SC] Sent spake2p msg1
[1624996233588] [0x48e69a] CHIP: [EM] Received message of type 35 and protocolId 0 on exchange 44249
[1624996233588] [0x48e69a] CHIP: [SC] Received spake2p msg2
[1624996233588] [0x48e69a] CHIP: [SC] Peer assigned session key ID 0
[1624996233588] [0x48e69a] CHIP: [SC] Sent spake2p msg3
[1624996233588] [0x48e69a] CHIP: [IN] New pairing for device 0x0000000000bc5c01, key 0!!
[1624996233588] [0x48e69a] CHIP: [CTL] Remote device completed SPAKE2+ handshake
[1624996233588] [0x48e69a] CHIP: [CTL] Sending root certificate to the device
[1624996233588] [0x48e69a] CHIP: [DMG] ICR moving to [Initialize]
[1624996233588] [0x48e69a] CHIP: [DMG] ICR moving to [AddCommand]
[1624996233588] [0x48e69a] CHIP: [IN] Secure message was encrypted: Msg ID 0
[1624996233588] [0x48e69a] CHIP: [IN] Encrypted message 0x70000ea6bc30 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44250.
[1624996233588] [0x48e69a] CHIP: [IN] Sending msg 0x70000ea6bc30 to 0x0000000000BC5C01 at utc time:<PHONE_NUMBER> msec
[1624996233588] [0x48e69a] CHIP: [IN] Sending secure msg on generic transport
[1624996233588] [0x48e69a] CHIP: [IN] Secure msg send status No Error
[1624996233588] [0x48e69a] CHIP: [DMG] ICR moving to [   Sending]
[1624996233588] [0x48e69a] CHIP: [CTL] Sent root certificate to the device
[1624996234893] [0x48e5a7] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 9
[1624996234893] [0x48e5a7] CHIP: [IN] Setting fabricID BC5C01 on admin.
[1624996234893] [0x48e5a7] CHIP: [IN] Since admin was modified, persisting changes to KVS
[1624996234894] [0x48e5a7] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44250
[1624996234894] [0x48e5a7] CHIP: [DMG] InvokeCommand =
[1624996234894] [0x48e5a7] CHIP: [DMG] {
[1624996234894] [0x48e5a7] CHIP: [DMG] 	CommandList =
[1624996234894] [0x48e5a7] CHIP: [DMG] 	[
[1624996234894] [0x48e5a7] CHIP: [DMG] 		CommandDataElement =
[1624996234894] [0x48e5a7] CHIP: [DMG] 		{
[1624996234894] [0x48e5a7] CHIP: [DMG] 			CommandPath =
[1624996234894] [0x48e5a7] CHIP: [DMG] 			{
[1624996234894] [0x48e5a7] CHIP: [DMG] 				EndpointId = 0x0,
[1624996234894] [0x48e5a7] CHIP: [DMG] 				ClusterId = 0x3e,
[1624996234894] [0x48e5a7] CHIP: [DMG] 				CommandId = 0xa1,
[1624996234894] [0x48e5a7] CHIP: [DMG] 			},
[1624996234894] [0x48e5a7] CHIP: [DMG]
[1624996234894] [0x48e5a7] CHIP: [DMG] 			StatusElement =
[1624996234894] [0x48e5a7] CHIP: [DMG] 			{
[1624996234894] [0x48e5a7] CHIP: [DMG] 				GeneralCode = 0x0,
[1624996234894] [0x48e5a7] CHIP: [DMG] 				ProtocolId = 0x5,
[1624996234894] [0x48e5a7] CHIP: [DMG] 				protocolCode = 0x0,
[1624996234894] [0x48e5a7] CHIP: [DMG] 			},
[1624996234894] [0x48e5a7] CHIP: [DMG]
[1624996234894] [0x48e5a7] CHIP: [DMG] 		},
[1624996234894] [0x48e5a7] CHIP: [DMG]
[1624996234894] [0x48e5a7] CHIP: [DMG] 	],
[1624996234894] [0x48e5a7] CHIP: [DMG]
[1624996234894] [0x48e5a7] CHIP: [DMG] }
[1624996234894] [0x48e5a7] CHIP: [ZCL] DefaultResponse:
[1624996234894] [0x48e5a7] CHIP: [ZCL]   Transaction: 0x106c9a548
[1624996234894] [0x48e5a7] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624996234894] [0x48e5a7] CHIP: [CTL] Device confirmed that it has received the root certificate
[1624996234894] [0x48e5a7] CHIP: [CTL] Sending OpCSR request to 0x7ffee9138690 device
[1624996234894] [0x48e5a7] CHIP: [DMG] ICR moving to [Initialize]
[1624996234894] [0x48e5a7] CHIP: [DMG] ICR moving to [AddCommand]
[1624996234894] [0x48e5a7] CHIP: [IN] Secure message was encrypted: Msg ID 1
[1624996234894] [0x48e5a7] CHIP: [IN] Encrypted message 0x70000eb71880 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44251.
[1624996234894] [0x48e5a7] CHIP: [IN] Sending msg 0x70000eb71880 to 0x0000000000BC5C01 at utc time:<PHONE_NUMBER> msec
[1624996234894] [0x48e5a7] CHIP: [IN] Sending secure msg on generic transport
[1624996234894] [0x48e5a7] CHIP: [IN] Secure msg send status No Error
[1624996234894] [0x48e5a7] CHIP: [DMG] ICR moving to [   Sending]
[1624996234894] [0x48e5a7] CHIP: [CTL] Sent OpCSR request, waiting for the CSR
[1624996234894] [0x48e5a7] CHIP: [DMG] ICR moving to [Uninitiali]
[1624996237863] [0x48e69a] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 9
[1624996237863] [0x48e69a] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44251
[1624996237863] [0x48e69a] CHIP: [DMG] InvokeCommand =
[1624996237863] [0x48e69a] CHIP: [DMG] {
[1624996237863] [0x48e69a] CHIP: [DMG] 	CommandList =
[1624996237863] [0x48e69a] CHIP: [DMG] 	[
[1624996237863] [0x48e69a] CHIP: [DMG] 		CommandDataElement =
[1624996237863] [0x48e69a] CHIP: [DMG] 		{
[1624996237863] [0x48e69a] CHIP: [DMG] 			CommandPath =
[1624996237863] [0x48e69a] CHIP: [DMG] 			{
[1624996237863] [0x48e69a] CHIP: [DMG] 				EndpointId = 0x0,
[1624996237863] [0x48e69a] CHIP: [DMG] 				ClusterId = 0x3e,
[1624996237863] [0x48e69a] CHIP: [DMG] 				CommandId = 0x5,
[1624996237863] [0x48e69a] CHIP: [DMG] 			},
[1624996237863] [0x48e69a] CHIP: [DMG]
[1624996237863] [0x48e69a] CHIP: [DMG] 			CommandData =
[1624996237863] [0x48e69a] CHIP: [DMG] 			{
[1624996237863] [0x48e69a] CHIP: [DMG] 				0x0 = [
[1624996237863] [0x48e69a] CHIP: [DMG] 					0x30, 0x81, 0xc8, 0x30, 0x70, 0x2, 0x1, 0x0, 0x30, 0xe, 0x31, 0xc, 0x30, 0xa, 0x6, 0x3, 0x55, 0x4, 0xa, 0xc, 0x3, 0x43, 0x53, 0x52, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6,
[1624996237863] [0x48e69a] CHIP: [DMG] 			]
[1624996237863] [0x48e69a] CHIP: [DMG] 				0x1 = [
[1624996237863] [0x48e69a] CHIP: [DMG] 					0xe6, 0xb4, 0xee, 0x6f, 0x58, 0xc5, 0x73, 0x3b, 0x28, 0x28, 0x12, 0x5d, 0x72, 0xf8, 0xab, 0x3b, 0xab, 0x4e, 0xa9, 0x62, 0xd6, 0xfa, 0xfa, 0x5b, 0x51, 0x60, 0xd9, 0xe0, 0xa4, 0x80, 0x8a, 0xc1,
[1624996237863] [0x48e69a] CHIP: [DMG] 			]
[1624996237863] [0x48e69a] CHIP: [DMG] 				0x2 = [
[1624996237863] [0x48e69a] CHIP: [DMG]
[1624996237863] [0x48e69a] CHIP: [DMG] 			]
[1624996237863] [0x48e69a] CHIP: [DMG] 				0x3 = [
[1624996237863] [0x48e69a] CHIP: [DMG]
[1624996237863] [0x48e69a] CHIP: [DMG] 			]
[1624996237863] [0x48e69a] CHIP: [DMG] 				0x4 = [
[1624996237863] [0x48e69a] CHIP: [DMG]
[1624996237863] [0x48e69a] CHIP: [DMG] 			]
[1624996237863] [0x48e69a] CHIP: [DMG] 				0x5 = [
[1624996237863] [0x48e69a] CHIP: [DMG]
[1624996237863] [0x48e69a] CHIP: [DMG] 			]
[1624996237863] [0x48e69a] CHIP: [DMG] 			},
[1624996237863] [0x48e69a] CHIP: [DMG] 		},
[1624996237863] [0x48e69a] CHIP: [DMG]
[1624996237863] [0x48e69a] CHIP: [DMG] 	],
[1624996237863] [0x48e69a] CHIP: [DMG]
[1624996237864] [0x48e69a] CHIP: [DMG] }
[1624996237864] [0x48e69a] CHIP: [ZCL] Received Cluster Command: Cluster=3e Command=5 Endpoint=0
[1624996237864] [0x48e69a] CHIP: [ZCL] OpCSRResponse:
[1624996237864] [0x48e69a] CHIP: [ZCL]   CSR: 203
[1624996237864] [0x48e69a] CHIP: [ZCL]   CSRNonce: 32
[1624996237864] [0x48e69a] CHIP: [ZCL]   VendorReserved1: 0
[1624996237864] [0x48e69a] CHIP: [ZCL]   VendorReserved2: 0
[1624996237864] [0x48e69a] CHIP: [ZCL]   VendorReserved3: 0
[1624996237864] [0x48e69a] CHIP: [ZCL]   Signature: 0
[1624996237864] [0x48e69a] CHIP: [CTL] Received certificate signing request from the device
[1624996237864] [0x48e69a] CHIP: [CTL] Getting intermediate CA certificate from the issuer
[1624996237864] [0x48e69a] CHIP: [CTL] GetIntermediateCACertificate returned 4190
[1624996237864] [0x48e69a] CHIP: [CTL] Intermediate CA is not needed
[1624996237865] [0x48e69a] CHIP: [CTL] Sending operational certificate to the device
[1624996237865] [0x48e69a] CHIP: [DMG] ICR moving to [Initialize]
[1624996237865] [0x48e69a] CHIP: [DMG] ICR moving to [AddCommand]
[1624996237865] [0x48e69a] CHIP: [IN] Secure message was encrypted: Msg ID 2
[1624996237865] [0x48e69a] CHIP: [IN] Encrypted message 0x70000ea6b140 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44252.
[1624996237865] [0x48e69a] CHIP: [IN] Sending msg 0x70000ea6b140 to 0x0000000000BC5C01 at utc time:<PHONE_NUMBER> msec
[1624996237865] [0x48e69a] CHIP: [IN] Sending secure msg on generic transport
[1624996237865] [0x48e69a] CHIP: [IN] Secure msg send status No Error
[1624996237865] [0x48e69a] CHIP: [DMG] ICR moving to [   Sending]
[1624996237865] [0x48e69a] CHIP: [CTL] Sent operational certificate to the device
[1624996237865] [0x48e69a] CHIP: [DMG] ICR moving to [Uninitiali]
[1624996239213] [0x48e69a] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 9
[1624996239213] [0x48e69a] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44252
[1624996239214] [0x48e69a] CHIP: [DMG] InvokeCommand =
[1624996239214] [0x48e69a] CHIP: [DMG] {
[1624996239214] [0x48e69a] CHIP: [DMG] 	CommandList =
[1624996239214] [0x48e69a] CHIP: [DMG] 	[
[1624996239214] [0x48e69a] CHIP: [DMG] 		CommandDataElement =
[1624996239214] [0x48e69a] CHIP: [DMG] 		{
[1624996239214] [0x48e69a] CHIP: [DMG] 			CommandPath =
[1624996239214] [0x48e69a] CHIP: [DMG] 			{
[1624996239214] [0x48e69a] CHIP: [DMG] 				EndpointId = 0x0,
[1624996239214] [0x48e69a] CHIP: [DMG] 				ClusterId = 0x3e,
[1624996239214] [0x48e69a] CHIP: [DMG] 				CommandId = 0x6,
[1624996239214] [0x48e69a] CHIP: [DMG] 			},
[1624996239214] [0x48e69a] CHIP: [DMG]
[1624996239214] [0x48e69a] CHIP: [DMG] 			StatusElement =
[1624996239214] [0x48e69a] CHIP: [DMG] 			{
[1624996239214] [0x48e69a] CHIP: [DMG] 				GeneralCode = 0x0,
[1624996239214] [0x48e69a] CHIP: [DMG] 				ProtocolId = 0x5,
[1624996239214] [0x48e69a] CHIP: [DMG] 				protocolCode = 0x0,
[1624996239214] [0x48e69a] CHIP: [DMG] 			},
[1624996239214] [0x48e69a] CHIP: [DMG]
[1624996239214] [0x48e69a] CHIP: [DMG] 		},
[1624996239214] [0x48e69a] CHIP: [DMG]
[1624996239214] [0x48e69a] CHIP: [DMG] 	],
[1624996239214] [0x48e69a] CHIP: [DMG]
[1624996239214] [0x48e69a] CHIP: [DMG] }
[1624996239214] [0x48e69a] CHIP: [ZCL] DefaultResponse:
[1624996239214] [0x48e69a] CHIP: [ZCL]   Transaction: 0x106c9a548
[1624996239214] [0x48e69a] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624996239214] [0x48e69a] CHIP: [CTL] Device confirmed that it has received the operational certificate
[1624996239214] [0x48e69a] CHIP: [CTL] Operational credentials provisioned on device 0x7ffee9138690
[1624996239220] [0x48e69a] CHIP: [TOO] Secure Pairing Success
[1624996239222] [0x48e69a] CHIP: [TOO] Pairing Success
[1624996239222] [0x48e69a] CHIP: [DMG] ICR moving to [Initialize]
[1624996239222] [0x48e69a] CHIP: [DMG] ICR moving to [AddCommand]
[1624996239222] [0x48e69a] CHIP: [IN] Connection from 'BLE' expired
[1624996239222] [0x48e69a] CHIP: [CTL] OnConnectionExpired was called for unknown device, ignoring it.
[1624996239222] [0x48e69a] CHIP: [IN] New pairing for device 0x0000000000bc5c01, key 0!!
[1624996239222] [0x48e69a] CHIP: [IN] Secure message was encrypted: Msg ID 4
[1624996239222] [0x48e69a] CHIP: [IN] Encrypted message 0x70000ea6b750 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44253.
[1624996239222] [0x48e69a] CHIP: [IN] Sending msg 0x70000ea6b750 to 0x0000000000BC5C01 at utc time:<PHONE_NUMBER> msec
[1624996239222] [0x48e69a] CHIP: [IN] Sending secure msg on generic transport
[1624996239222] [0x48e69a] CHIP: [IN] Secure msg send status No Error
[1624996239222] [0x48e69a] CHIP: [DMG] ICR moving to [   Sending]
[1624996239222] [0x48e69a] CHIP: [DMG] ICR moving to [Uninitiali]
[1624996240158] [0x48e5a7] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 9
[1624996240158] [0x48e5a7] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44253
[1624996240158] [0x48e5a7] CHIP: [DMG] InvokeCommand =
[1624996240158] [0x48e5a7] CHIP: [DMG] {
[1624996240158] [0x48e5a7] CHIP: [DMG] 	CommandList =
[1624996240158] [0x48e5a7] CHIP: [DMG] 	[
[1624996240158] [0x48e5a7] CHIP: [DMG] 		CommandDataElement =
[1624996240158] [0x48e5a7] CHIP: [DMG] 		{
[1624996240158] [0x48e5a7] CHIP: [DMG] 			CommandPath =
[1624996240158] [0x48e5a7] CHIP: [DMG] 			{
[1624996240158] [0x48e5a7] CHIP: [DMG] 				EndpointId = 0x0,
[1624996240158] [0x48e5a7] CHIP: [DMG] 				ClusterId = 0x31,
[1624996240158] [0x48e5a7] CHIP: [DMG] 				CommandId = 0x2,
[1624996240158] [0x48e5a7] CHIP: [DMG] 			},
[1624996240158] [0x48e5a7] CHIP: [DMG]
[1624996240158] [0x48e5a7] CHIP: [DMG] 			StatusElement =
[1624996240158] [0x48e5a7] CHIP: [DMG] 			{
[1624996240158] [0x48e5a7] CHIP: [DMG] 				GeneralCode = 0x0,
[1624996240158] [0x48e5a7] CHIP: [DMG] 				ProtocolId = 0x5,
[1624996240158] [0x48e5a7] CHIP: [DMG] 				protocolCode = 0x0,
[1624996240158] [0x48e5a7] CHIP: [DMG] 			},
[1624996240158] [0x48e5a7] CHIP: [DMG]
[1624996240158] [0x48e5a7] CHIP: [DMG] 		},
[1624996240158] [0x48e5a7] CHIP: [DMG]
[1624996240158] [0x48e5a7] CHIP: [DMG] 	],
[1624996240158] [0x48e5a7] CHIP: [DMG]
[1624996240158] [0x48e5a7] CHIP: [DMG] }
[1624996240158] [0x48e5a7] CHIP: [ZCL] DefaultResponse:
[1624996240158] [0x48e5a7] CHIP: [ZCL]   Transaction: 0x106c9a658
[1624996240158] [0x48e5a7] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624996240158] [0x48e5a7] CHIP: [TOO] AddNetworkResponse
[1624996240158] [0x48e5a7] CHIP: [DMG] ICR moving to [Initialize]
[1624996240158] [0x48e5a7] CHIP: [DMG] ICR moving to [AddCommand]
[1624996240158] [0x48e5a7] CHIP: [IN] Secure message was encrypted: Msg ID 5
[1624996240158] [0x48e5a7] CHIP: [IN] Encrypted message 0x70000eb71890 from 0x000000000001B669 to 0x0000000000BC5C01 of type 8 and protocolId 5 on exchange 44254.
[1624996240158] [0x48e5a7] CHIP: [IN] Sending msg 0x70000eb71890 to 0x0000000000BC5C01 at utc time:<PHONE_NUMBER> msec
[1624996240158] [0x48e5a7] CHIP: [IN] Sending secure msg on generic transport
[1624996240158] [0x48e5a7] CHIP: [IN] Secure msg send status No Error
[1624996240158] [0x48e5a7] CHIP: [DMG] ICR moving to [   Sending]
[1624996240158] [0x48e5a7] CHIP: [DMG] ICR moving to [Uninitiali]
[1624996241193] [0x48e69a] CHIP: [IN] Secure transport received message destined to fabric 0, node 0x000000000001B669. Key ID 9
[1624996241193] [0x48e69a] CHIP: [EM] Received message of type 9 and protocolId 5 on exchange 44254
[1624996241194] [0x48e69a] CHIP: [DMG] InvokeCommand =
[1624996241194] [0x48e69a] CHIP: [DMG] {
[1624996241194] [0x48e69a] CHIP: [DMG] 	CommandList =
[1624996241194] [0x48e69a] CHIP: [DMG] 	[
[1624996241194] [0x48e69a] CHIP: [DMG] 		CommandDataElement =
[1624996241194] [0x48e69a] CHIP: [DMG] 		{
[1624996241194] [0x48e69a] CHIP: [DMG] 			CommandPath =
[1624996241194] [0x48e69a] CHIP: [DMG] 			{
[1624996241194] [0x48e69a] CHIP: [DMG] 				EndpointId = 0x0,
[1624996241194] [0x48e69a] CHIP: [DMG] 				ClusterId = 0x31,
[1624996241194] [0x48e69a] CHIP: [DMG] 				CommandId = 0xc,
[1624996241194] [0x48e69a] CHIP: [DMG] 			},
[1624996241194] [0x48e69a] CHIP: [DMG]
[1624996241194] [0x48e69a] CHIP: [DMG] 			StatusElement =
[1624996241194] [0x48e69a] CHIP: [DMG] 			{
[1624996241194] [0x48e69a] CHIP: [DMG] 				GeneralCode = 0x0,
[1624996241194] [0x48e69a] CHIP: [DMG] 				ProtocolId = 0x5,
[1624996241194] [0x48e69a] CHIP: [DMG] 				protocolCode = 0x0,
[1624996241194] [0x48e69a] CHIP: [DMG] 			},
[1624996241194] [0x48e69a] CHIP: [DMG]
[1624996241194] [0x48e69a] CHIP: [DMG] 		},
[1624996241194] [0x48e69a] CHIP: [DMG]
[1624996241194] [0x48e69a] CHIP: [DMG] 	],
[1624996241194] [0x48e69a] CHIP: [DMG]
[1624996241194] [0x48e69a] CHIP: [DMG] }
[1624996241194] [0x48e69a] CHIP: [ZCL] DefaultResponse:
[1624996241194] [0x48e69a] CHIP: [ZCL]   Transaction: 0x106c9a548
[1624996241194] [0x48e69a] CHIP: [ZCL]   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1624996241194] [0x48e69a] CHIP: [TOO] EnableNetworkResponse

On my RP4 side.

[1624996234.799119][22714] CHIP:DL: Device 8C:85:90:58:49:03 (Path: /org/bluez/hci0/dev_8C_85_90_58_49_03) Connected
[1624996235.718697][22714] CHIP:DL: BluezCharacteristicAcquireWrite is called, conn: 0xffff94049730
[1624996235.720747][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996235.720922][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996235.721157][22711] CHIP:BLE: local and remote recv window sizes = 3
[1624996235.721219][22711] CHIP:BLE: selected BTP version 3
[1624996235.721256][22711] CHIP:BLE: using BTP fragment sizes rx 128 / tx 20.
[1624996236.124193][22714] CHIP:DL: CHIPoBLE subscribe received
[1624996236.124403][22711] CHIP:IN: BLE EndPoint 0xaaaacb129550 Connection Complete
[1624996236.124491][22711] CHIP:DL: HandlePlatformSpecificBLEEvent 32777
[1624996236.124544][22711] CHIP:DL: Receive kCHIPoBLEConnectionEstablished
[1624996236.258009][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996236.302935][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996236.303388][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996236.303655][22711] CHIP:EM: Received message of type 32 and protocolId 0 on exchange 44249
[1624996236.303729][22711] CHIP:EM: ec id: 44249, Delegate: 0x0xaaaacb12b5f0
[1624996236.303784][22711] CHIP:SC: Received PBKDF param request
[1624996236.306160][22711] CHIP:SC: Sent PBKDF param response
[1624996236.438108][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996236.528188][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996236.572341][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996236.572761][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996236.708134][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996236.797971][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996236.842331][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996236.842588][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996236.977978][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996237.068234][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996237.068707][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996237.068974][22711] CHIP:EM: Received message of type 34 and protocolId 0 on exchange 44249
[1624996237.069049][22711] CHIP:SC: Received spake2p msg1
[1624996237.070735][22711] CHIP:SC: Peer assigned session key ID 9
[1624996237.073020][22711] CHIP:SC: Sent spake2p msg2
[1624996237.248229][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996237.338003][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996237.382388][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996237.383036][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996237.517941][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996237.608157][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996237.652377][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996237.652582][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996237.788284][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996237.878001][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996237.922362][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996237.922643][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996238.058068][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996238.147950][22714] CHIP:BLE: Indication confirmation, 0xffff94049730
[1624996238.192340][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996238.192556][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996238.283067][22714] CHIP:DL: c1 BluezCharacteristicWriteFD mtu, 515
[1624996238.283459][22714] CHIP:BLE: Write request received debug 0xffff94049730
[1624996238.283801][22711] CHIP:EM: Received message of type 36 and protocolId 0 on exchange 44249
[1624996238.283877][22711] CHIP:SC: Received spake2p msg3
[1624996238.284036][22711] CHIP:IN: New pairing for device 0x0000000000000000, key 9!!
[1624996238.284179][22711] CHIP:SVR: Device completed SPAKE2+ handshake
[1624996238.284261][22711] CHIP:SVR: Persisting admin ID 0, next available 1
[1624996238.289501][22711] CHIP:SVR: Stored value in server storage
[1624996238.290037][22711] CHIP:DL: writing settings to file (/tmp/chip_server_kvs.tmp)
[1624996238.291051][22711] CHIP:DL: renamed tmp file to file (/tmp/chip_server_kvs)
[1624996238.291127][22711] CHIP:DIS: Admin (0) persisted to storage. Calling OnAdminPersistedToStorage
[1624996238.291174][22711] CHIP:ZCL: OpCreds: Admin 0 was persisted to storage. FabricId<PHONE_NUMBER>0000000, NodeId 000000000E1367A60, VendorId 0xCB0839E0