ubuntu@matter-te-7:~/temp/connectedhomeip$ sudo out/chip-tool/chip-tool pairing ble-wifi 12344321 WIFI_SSID WIFI_PASSWORD 20202021 3840 [1638338542.392396][189523:189523] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-L1YqGM) [1638338542.393068][189523:189523] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1638338542.393128][189523:189523] CHIP:DL: NVS set: chip-counters/reboot-count = 108 (0x6C) [1638338542.393932][189523:189523] CHIP:DL: Got Ethernet interface: eth0 [1638338542.394465][189523:189523] CHIP:DL: Found the primary Ethernet interface:eth0 [1638338542.395044][189523:189523] CHIP:DL: Got WiFi interface: wlan0 [1638338542.395123][189523:189523] CHIP:DL: Failed to reset WiFi statistic counts [1638338542.395191][189523:189523] CHIP:IN: UDP::Init bind&listen port=5542 [1638338542.395310][189523:189523] CHIP:IN: UDP::Init bound to port=5542 [1638338542.395337][189523:189523] CHIP:IN: UDP::Init bind&listen port=5542 [1638338542.395428][189523:189523] CHIP:IN: UDP::Init bound to port=5542 [1638338542.395482][189523:189523] CHIP:IN: TransportMgr initialized [1638338542.395528][189523:189523] CHIP:DIS: Init fabric pairing table with server storage [1638338542.395899][189523:189523] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-9WomwS) [1638338542.396480][189523:189523] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1638338542.396536][189523:189523] CHIP:DL: NVS set: chip-counters/GlobalMCTR = 108000 (0x1A5E0) [1638338542.396664][189523:189523] CHIP:CTL: System State Initialized... [1638338542.399322][189523:189523] CHIP:CTL: Generating NOC [1638338542.399692][189523:189523] CHIP:CTL: Generating ICAC [1638338542.402552][189523:189523] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPoint.cpp:1395: Inet Error 0x00000110: Address not found [1638338542.405949][189523:189523] CHIP:ZCL: Using ZAP configuration... [1638338542.406629][189523:189523] CHIP:DIS: Verifying the received credentials [1638338542.408874][189523:189523] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey [1638338542.408926][189523:189523] CHIP:IN: 0x04, 0x3c, 0xce, 0x8a, 0x2c, 0x16, 0x94, 0x9e, [1638338542.408952][189523:189523] CHIP:IN: 0x36, 0x3c, 0x8f, 0xdd, 0x1d, 0x10, 0xc4, 0x52, [1638338542.408977][189523:189523] CHIP:IN: 0x6d, 0x55, 0xe7, 0x15, 0xc6, 0x70, 0xc3, 0x38, [1638338542.409002][189523:189523] CHIP:IN: 0x2d, 0xef, 0xe2, 0xbf, 0x96, 0x7d, 0x13, 0x05, [1638338542.409027][189523:189523] CHIP:IN: 0x8b, 0x49, 0x94, 0x4b, 0xd7, 0x0b, 0xa8, 0x88, [1638338542.409052][189523:189523] CHIP:IN: 0xf3, 0x2a, 0x91, 0x13, 0x0e, 0xd9, 0x47, 0x06, [1638338542.409108][189523:189523] CHIP:IN: 0x36, 0x58, 0x6a, 0x3b, 0xcd, 0x5a, 0x0d, 0x24, [1638338542.409132][189523:189523] CHIP:IN: 0xf8, 0x97, 0x46, 0x93, 0xeb, 0x96, 0x18, 0xea, [1638338542.409154][189523:189523] CHIP:IN: 0xa2, [1638338542.409215][189523:189523] CHIP:IN: Generated compressed fabric ID [1638338542.409244][189523:189523] CHIP:IN: 0xe8, 0x3c, 0x10, 0x30, 0xb7, 0x22, 0xe1, 0xef, [1638338542.409277][189523:189523] CHIP:DIS: Added new fabric at index: 1, Initialized: 1 [1638338542.409302][189523:189523] CHIP:DIS: Assigned compressed fabric ID: 0xE83C1030B722E1EF, node ID: 0x000000000001B669 [1638338542.409327][189523:189523] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xE83C1030B722E1EF [1638338542.409463][189523:189523] CHIP:IN: UDP::Init bind&listen port=5550 [1638338542.409607][189523:189523] CHIP:IN: UDP::Init bound to port=5550 [1638338542.409635][189523:189523] CHIP:IN: UDP::Init bind&listen port=5550 [1638338542.409739][189523:189523] CHIP:IN: UDP::Init bound to port=5550 [1638338542.409764][189523:189523] CHIP:IN: TransportMgr initialized [1638338542.410070][189523:189528] CHIP:DL: CHIP task running [1638338542.410503][189523:189528] CHIP:SC: Assigned local session key ID 23 [1638338542.410608][189523:189528] CHIP:IN: Prepared plaintext message 0xffffa77eddb0 to 0x0000000000000000 (0) of type 0x20 and protocolId (0, 0) on exchange 35144i with MessageCounter:2664102293. [1638338542.410658][189523:189528] CHIP:IN: Sending plaintext msg 0xffffa77eddb0 with MessageCounter:2664102293 to 0x0000000000000000 at monotonic time: 99481567 msec [1638338542.410703][189523:189528] CHIP:IN: Message appended to BLE send queue [1638338542.410730][189523:189528] CHIP:SC: Sent PBKDF param request [1638338542.411863][189523:189529] CHIP:DL: TRACE: Bluez mainloop starting Thread [1638338542.412228][189523:189526] CHIP:DL: TRACE: Bus acquired for name C-e453 [1638338542.425069][189523:189528] CHIP:DL: PlatformBlueZInit init success [1638338542.433920][189523:189526] CHIP:BLE: BLE removing known devices. [1638338542.454966][189523:189526] CHIP:BLE: BLE initiating scan. [1638338542.879579][189523:189526] CHIP:BLE: Device 2C:4C:C6:11:03:2D does not look like a CHIP device. [1638338542.882989][189523:189526] CHIP:BLE: Device 61:0E:F9:AD:30:71 does not look like a CHIP device. [1638338542.895244][189523:189526] CHIP:BLE: Device 2C:4C:C6:11:03:2D does not look like a CHIP device. [1638338543.027135][189523:189526] CHIP:BLE: New device scanned: D4:4D:A4:A0:02:A5 [1638338543.027234][189523:189526] CHIP:BLE: Device discriminator match. Attempting to connect. [1638338543.031539][189523:189526] CHIP:BLE: Scan complete notification without an active scan. [1638338543.397848][189523:189526] CHIP:DL: ConnectDevice complete [1638338543.920910][189523:189526] CHIP:DL: Char1 /org/bluez/hci0/dev_D4_4D_A4_A0_02_A5/service0007 [1638338543.920986][189523:189526] CHIP:DL: Char1 /org/bluez/hci0/dev_D4_4D_A4_A0_02_A5/service0007 [1638338543.921052][189523:189526] CHIP:DL: Char1 /org/bluez/hci0/dev_D4_4D_A4_A0_02_A5/service0007 [1638338543.921091][189523:189526] CHIP:DL: Char1 /org/bluez/hci0/dev_D4_4D_A4_A0_02_A5/service0007 [1638338543.921134][189523:189526] CHIP:DL: Char1 /org/bluez/hci0/dev_D4_4D_A4_A0_02_A5/service0007 [1638338543.921171][189523:189526] CHIP:DL: Char1 /org/bluez/hci0/dev_D4_4D_A4_A0_02_A5/service0007 [1638338543.921219][189523:189526] CHIP:DL: New BLE connection 0xffff9c030120, device D4:4D:A4:A0:02:A5, path /org/bluez/hci0/dev_D4_4D_A4_A0_02_A5 [1638338543.921488][189523:189528] CHIP:IN: BleConnectionComplete: endPoint 0xaaaad182d588 [1638338544.372527][189523:189528] CHIP:BLE: subscribe complete, ep = 0xaaaad182d588 [1638338544.373678][189523:189528] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4 [1638338544.373735][189523:189528] CHIP:BLE: using BTP fragment sizes rx 20 / tx 20. [1638338544.373788][189523:189528] CHIP:BLE: local and remote recv window size = 5 [1638338544.373989][189523:189528] CHIP:IN: BLE EndPoint 0xaaaad182d588 Connection Complete [1638338545.302222][189523:189528] CHIP:EM: Received message of type 0x21 with protocolId (0, 0) and MessageCounter:659506920 on exchange 35144i [1638338545.302340][189523:189528] CHIP:SC: Received PBKDF param response [1638338545.302431][189523:189528] CHIP:SC: Peer assigned session ID 1 [1638338545.305644][189523:189528] CHIP:IN: Prepared plaintext message 0xffffa77ed8a0 to 0x0000000000000000 (0) of type 0x22 and protocolId (0, 0) on exchange 35144i with MessageCounter:2664102294. [1638338545.305765][189523:189528] CHIP:IN: Sending plaintext msg 0xffffa77ed8a0 with MessageCounter:2664102294 to 0x0000000000000000 at monotonic time: 99484462 msec [1638338545.305845][189523:189528] CHIP:SC: Sent spake2p msg1 [1638338547.835992][189523:189528] CHIP:EM: Received message of type 0x23 with protocolId (0, 0) and MessageCounter:659506921 on exchange 35144i [1638338547.836119][189523:189528] CHIP:SC: Received spake2p msg2 [1638338547.838921][189523:189528] CHIP:IN: Prepared plaintext message 0xffffa77ed980 to 0x0000000000000000 (0) of type 0x24 and protocolId (0, 0) on exchange 35144i with MessageCounter:2664102295. [1638338547.839019][189523:189528] CHIP:IN: Sending plaintext msg 0xffffa77ed980 with MessageCounter:2664102295 to 0x0000000000000000 at monotonic time: 99486995 msec [1638338547.839191][189523:189528] CHIP:SC: Sent spake2p msg3 [1638338548.174862][189523:189528] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:659506922 on exchange 35144i [1638338548.174997][189523:189528] CHIP:IN: New secure session created for device 0x0000000000BC5C01, key 1!! [1638338548.175156][189523:189528] CHIP:CTL: Remote device completed SPAKE2+ handshake [1638338548.175216][189523:189528] CHIP:CTL: Sending Certificate Chain request to 0xffffac4c9808 device [1638338548.175389][189523:189528] CHIP:DMG: ICR moving to [AddingComm] [1638338548.175520][189523:189528] CHIP:DMG: ICR moving to [AddedComma] [1638338548.175696][189523:189528] CHIP:IN: Prepared encrypted message 0xffffa77ed690 to 0x0000000000BC5C01 (1) of type 0x8 and protocolId (0, 1) on exchange 35145i with MessageCounter:1. [1638338548.175790][189523:189528] CHIP:IN: Sending encrypted msg 0xffffa77ed690 with MessageCounter:1 to 0x0000000000BC5C01 (1) at monotonic time: 99487332 msec [1638338548.175987][189523:189528] CHIP:DMG: ICR moving to [CommandSen] [1638338548.176050][189523:189528] CHIP:CTL: Sent Certificate Chain request, waiting for the DAC Certificate [1638338549.346204][189523:189528] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:1 on exchange 35145i [1638338549.346298][189523:189528] CHIP:DMG: InvokeResponseMessage = [1638338549.346341][189523:189528] CHIP:DMG: { [1638338549.346382][189523:189528] CHIP:DMG: suppressResponse = false, [1638338549.346422][189523:189528] CHIP:DMG: InvokeResponses = [1638338549.346464][189523:189528] CHIP:DMG: [ [1638338549.346503][189523:189528] CHIP:DMG: InvokeResponseIB = [1638338549.346585][189523:189528] CHIP:DMG: { [1638338549.346724][189523:189528] CHIP:DMG: CommandDataIB = [1638338549.346880][189523:189528] CHIP:DMG: { [1638338549.347031][189523:189528] CHIP:DMG: CommandPathIB = [1638338549.347205][189523:189528] CHIP:DMG: { [1638338549.347379][189523:189528] CHIP:DMG: EndpointId = 0x0, [1638338549.347617][189523:189528] CHIP:DMG: ClusterId = 0x3e, [1638338549.347817][189523:189528] CHIP:DMG: CommandId = 0x3, [1638338549.348007][189523:189528] CHIP:DMG: }, [1638338549.348185][189523:189528] CHIP:DMG: [1638338549.348336][189523:189528] CHIP:DMG: CommandData = [1638338549.348509][189523:189528] CHIP:DMG: { [1638338549.348680][189523:189528] CHIP:DMG: 0x0 = [ [1638338549.348868][189523:189528] CHIP:DMG: ... (byte string too long) ... [1638338549.349080][189523:189528] CHIP:DMG: ] [1638338549.349253][189523:189528] CHIP:DMG: }, [1638338549.349420][189523:189528] CHIP:DMG: }, [1638338549.349664][189523:189528] CHIP:DMG: [1638338549.349713][189523:189528] CHIP:DMG: }, [1638338549.349767][189523:189528] CHIP:DMG: [1638338549.349808][189523:189528] CHIP:DMG: ], [1638338549.349859][189523:189528] CHIP:DMG: [1638338549.349896][189523:189528] CHIP:DMG: }, [1638338549.349978][189523:189528] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1638338549.350037][189523:189528] CHIP:ZCL: CertificateChainResponse: [1638338549.350073][189523:189528] CHIP:ZCL: Certificate: 451 [1638338549.350113][189523:189528] CHIP:CTL: Received certificate chain from the device [1638338549.350153][189523:189528] CHIP:CTL: Sending Certificate Chain request to 0xffffac4c9808 device [1638338549.350268][189523:189528] CHIP:DMG: ICR moving to [AddingComm] [1638338549.350319][189523:189528] CHIP:DMG: ICR moving to [AddedComma] [1638338549.350457][189523:189528] CHIP:IN: Prepared encrypted message 0xffffa77ed080 to 0x0000000000BC5C01 (1) of type 0x8 and protocolId (0, 1) on exchange 35146i with MessageCounter:2. [1638338549.350523][189523:189528] CHIP:IN: Sending encrypted msg 0xffffa77ed080 with MessageCounter:2 to 0x0000000000BC5C01 (1) at monotonic time: 99488507 msec [1638338549.350686][189523:189528] CHIP:DMG: ICR moving to [CommandSen] [1638338549.350730][189523:189528] CHIP:CTL: Sent Certificate Chain request, waiting for the DAC Certificate [1638338549.350789][189523:189528] CHIP:DMG: ICR moving to [AwaitingDe] [1638338550.564826][189523:189528] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:2 on exchange 35146i [1638338550.564962][189523:189528] CHIP:DMG: InvokeResponseMessage = [1638338550.565024][189523:189528] CHIP:DMG: { [1638338550.565085][189523:189528] CHIP:DMG: suppressResponse = false, [1638338550.565146][189523:189528] CHIP:DMG: InvokeResponses = [1638338550.565207][189523:189528] CHIP:DMG: [ [1638338550.565265][189523:189528] CHIP:DMG: InvokeResponseIB = [1638338550.565526][189523:189528] CHIP:DMG: { [1638338550.565600][189523:189528] CHIP:DMG: CommandDataIB = [1638338550.565664][189523:189528] CHIP:DMG: { [1638338550.565739][189523:189528] CHIP:DMG: CommandPathIB = [1638338550.565823][189523:189528] CHIP:DMG: { [1638338550.565908][189523:189528] CHIP:DMG: EndpointId = 0x0, [1638338550.566002][189523:189528] CHIP:DMG: ClusterId = 0x3e, [1638338550.566088][189523:189528] CHIP:DMG: CommandId = 0x3, [1638338550.566169][189523:189528] CHIP:DMG: }, [1638338550.566257][189523:189528] CHIP:DMG: [1638338550.566338][189523:189528] CHIP:DMG: CommandData = [1638338550.566417][189523:189528] CHIP:DMG: { [1638338550.566481][189523:189528] CHIP:DMG: 0x0 = [ [1638338550.566561][189523:189528] CHIP:DMG: ... (byte string too long) ... [1638338550.566657][189523:189528] CHIP:DMG: ] [1638338550.566744][189523:189528] CHIP:DMG: }, [1638338550.566817][189523:189528] CHIP:DMG: }, [1638338550.566904][189523:189528] CHIP:DMG: [1638338550.566970][189523:189528] CHIP:DMG: }, [1638338550.567052][189523:189528] CHIP:DMG: [1638338550.567110][189523:189528] CHIP:DMG: ], [1638338550.567183][189523:189528] CHIP:DMG: [1638338550.567229][189523:189528] CHIP:DMG: }, [1638338550.567310][189523:189528] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1638338550.567477][189523:189528] CHIP:ZCL: CertificateChainResponse: [1638338550.567519][189523:189528] CHIP:ZCL: Certificate: 494 [1638338550.567563][189523:189528] CHIP:CTL: Received certificate chain from the device [1638338550.567606][189523:189528] CHIP:CTL: Sending Attestation Request to the device. [1638338550.567645][189523:189528] CHIP:CTL: Sending Attestation request to 0xffffac4c9808 device [1638338550.567720][189523:189528] CHIP:DMG: ICR moving to [AddingComm] [1638338550.567772][189523:189528] CHIP:DMG: ICR moving to [AddedComma] [1638338550.567916][189523:189528] CHIP:IN: Prepared encrypted message 0xffffa77ed070 to 0x0000000000BC5C01 (1) of type 0x8 and protocolId (0, 1) on exchange 35147i with MessageCounter:3. [1638338550.567987][189523:189528] CHIP:IN: Sending encrypted msg 0xffffa77ed070 with MessageCounter:3 to 0x0000000000BC5C01 (1) at monotonic time: 99489724 msec [1638338550.568154][189523:189528] CHIP:DMG: ICR moving to [CommandSen] [1638338550.568205][189523:189528] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information [1638338550.568270][189523:189528] CHIP:DMG: ICR moving to [AwaitingDe] [1638338552.124512][189523:189528] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:3 on exchange 35147i [1638338552.124648][189523:189528] CHIP:DMG: InvokeResponseMessage = [1638338552.124712][189523:189528] CHIP:DMG: { [1638338552.124772][189523:189528] CHIP:DMG: suppressResponse = false, [1638338552.124833][189523:189528] CHIP:DMG: InvokeResponses = [1638338552.124897][189523:189528] CHIP:DMG: [ [1638338552.124956][189523:189528] CHIP:DMG: InvokeResponseIB = [1638338552.125033][189523:189528] CHIP:DMG: { [1638338552.125098][189523:189528] CHIP:DMG: CommandDataIB = [1638338552.125184][189523:189528] CHIP:DMG: { [1638338552.125265][189523:189528] CHIP:DMG: CommandPathIB = [1638338552.125355][189523:189528] CHIP:DMG: { [1638338552.125440][189523:189528] CHIP:DMG: EndpointId = 0x0, [1638338552.125532][189523:189528] CHIP:DMG: ClusterId = 0x3e, [1638338552.125618][189523:189528] CHIP:DMG: CommandId = 0x1, [1638338552.125708][189523:189528] CHIP:DMG: }, [1638338552.125803][189523:189528] CHIP:DMG: [1638338552.125879][189523:189528] CHIP:DMG: CommandData = [1638338552.125960][189523:189528] CHIP:DMG: { [1638338552.126050][189523:189528] CHIP:DMG: 0x0 = [ [1638338552.126139][189523:189528] CHIP:DMG: ... (byte string too long) ... [1638338552.126234][189523:189528] CHIP:DMG: ] [1638338552.126316][189523:189528] CHIP:DMG: 0x1 = [ [1638338552.126433][189523:189528] CHIP:DMG: 0xd6, 0x55, 0x3f, 0x2d, 0x8, 0x3b, 0xbd, 0xed, 0x8c, 0x3d, 0xca, 0x68, 0x4e, 0xb3, 0xc7, 0xd6, 0x87, 0x8c, 0xb1, 0xf2, 0x24, 0xdf, 0x55, 0x81, 0x63, 0x33, 0xbe, 0x1, 0x6c, 0xc5, 0xdc, 0x43, 0x3e, 0x2f, 0x42, 0x93, 0x22, 0x8e, 0x56, 0x7e, 0xab, 0x6f, [1638338552.126528][189523:189528] CHIP:DMG: ] [1638338552.126610][189523:189528] CHIP:DMG: }, [1638338552.126695][189523:189528] CHIP:DMG: }, [1638338552.126791][189523:189528] CHIP:DMG: [1638338552.126861][189523:189528] CHIP:DMG: }, [1638338552.126946][189523:189528] CHIP:DMG: [1638338552.127006][189523:189528] CHIP:DMG: ], [1638338552.127082][189523:189528] CHIP:DMG: [1638338552.127137][189523:189528] CHIP:DMG: }, [1638338552.127252][189523:189528] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001 [1638338552.127334][189523:189528] CHIP:ZCL: AttestationResponse: [1638338552.127387][189523:189528] CHIP:ZCL: AttestationElements: 278 [1638338552.127437][189523:189528] CHIP:ZCL: Signature: 64 [1638338552.127551][189523:189528] CHIP:CTL: Received Attestation Information from the device [1638338552.135900][189523:189528] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device. [1638338552.135957][189523:189528] CHIP:CTL: Sending 'CSR request' command to the device. [1638338552.135982][189523:189528] CHIP:CTL: Sending OpCSR request to 0xffffac4c9808 device [1638338552.136045][189523:189528] CHIP:DMG: ICR moving to [AddingComm] [1638338552.136080][189523:189528] CHIP:DMG: ICR moving to [AddedComma] [1638338552.136195][189523:189528] CHIP:IN: Prepared encrypted message 0xffffa77ed080 to 0x0000000000BC5C01 (1) of type 0x8 and protocolId (0, 1) on exchange 35148i with MessageCounter:4. [1638338552.136246][189523:189528] CHIP:IN: Sending encrypted msg 0xffffa77ed080 with MessageCounter:4 to 0x0000000000BC5C01 (1) at monotonic time: 99491292 msec [1638338552.136375][189523:189528] CHIP:DMG: ICR moving to [CommandSen] [1638338552.136411][189523:189528] CHIP:CTL: Sent OpCSR request, waiting for the CSR [1638338552.136457][189523:189528] CHIP:DMG: ICR moving to [AwaitingDe] [1638338554.756944][189523:189528] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:4 on exchange 35148i [1638338554.757072][189523:189528] CHIP:DMG: InvokeResponseMessage = [1638338554.757137][189523:189528] CHIP:DMG: { [1638338554.757196][189523:189528] CHIP:DMG: suppressResponse = false, [1638338554.757258][189523:189528] CHIP:DMG: InvokeResponses = [1638338554.757319][189523:189528] CHIP:DMG: [ [1638338554.757378][189523:189528] CHIP:DMG: InvokeResponseIB = [1638338554.757486][189523:189528] CHIP:DMG: { [1638338554.757556][189523:189528] CHIP:DMG: CommandDataIB = [1638338554.757668][189523:189528] CHIP:DMG: { [1638338554.757767][189523:189528] CHIP:DMG: CommandPathIB = [1638338554.757860][189523:189528] CHIP:DMG: { [1638338554.757942][189523:189528] CHIP:DMG: EndpointId = 0x0, [1638338554.758039][189523:189528] CHIP:DMG: ClusterId = 0x3e, [1638338554.758125][189523:189528] CHIP:DMG: CommandId = 0x5, [1638338554.758215][189523:189528] CHIP:DMG: }, [1638338554.758310][189523:189528] CHIP:DMG: [1638338554.758386][189523:189528] CHIP:DMG: CommandData = [1638338554.758474][189523:189528] CHIP:DMG: { [1638338554.758556][189523:189528] CHIP:DMG: 0x0 = [ [1638338554.758690][189523:189528] CHIP:DMG: 0x15, 0x30, 0x1, 0xce, 0x30, 0x81, 0xcb, 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, 0x8, 0x2a, 0x86 [1638338554.758788][189523:189528] CHIP:DMG: ] [1638338554.758869][189523:189528] CHIP:DMG: 0x1 = [ [1638338554.758993][189523:189528] CHIP:DMG: 0x6f, 0x47, 0x1a, 0x28, 0x13, 0xfa, 0x74, 0xf9, 0xbf, 0x52, 0x9d, 0x99, 0xc5, 0xa1, 0x19, 0x6e, 0xae, 0x4e, 0xf9, 0xbc, 0x8a, 0x5e, 0x71, 0x57, 0xed, 0x9c, 0x7, 0x29, 0x83, 0xb5, 0xfe, 0x57, 0x9f, 0x73, 0xee, 0xee, 0x94, 0x9e, 0xc5, 0x31, 0xa0, 0xce [1638338554.759087][189523:189528] CHIP:DMG: ] [1638338554.759169][189523:189528] CHIP:DMG: }, [1638338554.759248][189523:189528] CHIP:DMG: }, [1638338554.759342][189523:189528] CHIP:DMG: [1638338554.759409][189523:189528] CHIP:DMG: }, [1638338554.759545][189523:189528] CHIP:DMG: [1638338554.759608][189523:189528] CHIP:DMG: ], [1638338554.759682][189523:189528] CHIP:DMG: [1638338554.759736][189523:189528] CHIP:DMG: }, [1638338554.759852][189523:189528] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005 [1638338554.759931][189523:189528] CHIP:ZCL: OpCSRResponse: [1638338554.759983][189523:189528] CHIP:ZCL: NOCSRElements: 246 [1638338554.760032][189523:189528] CHIP:ZCL: AttestationSignature: 64 [1638338554.760087][189523:189528] CHIP:CTL: Received certificate signing request from the device [1638338554.760137][189523:189528] CHIP:CTL: Getting certificate chain for the device from the issuer [1638338554.760190][189523:189528] CHIP:CTL: Verifying Certificate Signing Request [1638338554.761799][189523:189528] CHIP:CTL: Generating NOC [1638338554.762479][189523:189528] CHIP:CTL: Generating ICAC [1638338554.763142][189523:189528] CHIP:CTL: Providing certificate chain to the commissioner [1638338554.763215][189523:189528] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../examples/chip-tool/third_party/connectedhomeip/src/controller/ExampleOperationalCredentialsIssuer.cpp:183: Success [1638338554.763440][189523:189528] CHIP:CTL: Sending root certificate to the device [1638338554.763588][189523:189528] CHIP:DMG: ICR moving to [AddingComm] [1638338554.763655][189523:189528] CHIP:DMG: ICR moving to [AddedComma] [1638338554.763860][189523:189528] CHIP:IN: Prepared encrypted message 0xffffa77ecd90 to 0x0000000000BC5C01 (1) of type 0x8 and protocolId (0, 1) on exchange 35149i with MessageCounter:5. [1638338554.764149][189523:189528] CHIP:IN: Sending encrypted msg 0xffffa77ecd90 with MessageCounter:5 to 0x0000000000BC5C01 (1) at monotonic time: 99493920 msec [1638338554.764376][189523:189528] CHIP:DMG: ICR moving to [CommandSen] [1638338554.764443][189523:189528] CHIP:CTL: Sent root certificate to the device [1638338554.764797][189523:189528] CHIP:DMG: ICR moving to [AwaitingDe] [1638338556.706409][189523:189528] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:5 on exchange 35149i [1638338556.706554][189523:189528] CHIP:DMG: InvokeResponseMessage = [1638338556.706618][189523:189528] CHIP:DMG: { [1638338556.706678][189523:189528] CHIP:DMG: suppressResponse = false, [1638338556.706740][189523:189528] CHIP:DMG: InvokeResponses = [1638338556.706805][189523:189528] CHIP:DMG: [ [1638338556.706865][189523:189528] CHIP:DMG: InvokeResponseIB = [1638338556.706946][189523:189528] CHIP:DMG: { [1638338556.707016][189523:189528] CHIP:DMG: CommandStatusIB = [1638338556.707096][189523:189528] CHIP:DMG: { [1638338556.707171][189523:189528] CHIP:DMG: CommandPathIB = [1638338556.707260][189523:189528] CHIP:DMG: { [1638338556.707345][189523:189528] CHIP:DMG: EndpointId = 0x0, [1638338556.707441][189523:189528] CHIP:DMG: ClusterId = 0x3e, [1638338556.707596][189523:189528] CHIP:DMG: CommandId = 0xb, [1638338556.707686][189523:189528] CHIP:DMG: }, [1638338556.707783][189523:189528] CHIP:DMG: [1638338556.707865][189523:189528] CHIP:DMG: StatusIB = [1638338556.707953][189523:189528] CHIP:DMG: { [1638338556.708042][189523:189528] CHIP:DMG: status = 0x0, [1638338556.708125][189523:189528] CHIP:DMG: }, [1638338556.708216][189523:189528] CHIP:DMG: [1638338556.708291][189523:189528] CHIP:DMG: }, [1638338556.708383][189523:189528] CHIP:DMG: [1638338556.708451][189523:189528] CHIP:DMG: }, [1638338556.708532][189523:189528] CHIP:DMG: [1638338556.708591][189523:189528] CHIP:DMG: ], [1638338556.708664][189523:189528] CHIP:DMG: [1638338556.708718][189523:189528] CHIP:DMG: }, [1638338556.708825][189523:189528] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0 [1638338556.708889][189523:189528] CHIP:ZCL: DefaultResponse: [1638338556.708939][189523:189528] CHIP:ZCL: Transaction: 0xffff940111a0 [1638338556.708989][189523:189528] CHIP:ZCL: status: EMBER_ZCL_STATUS_SUCCESS (0x00) [1638338556.709047][189523:189528] CHIP:CTL: Device confirmed that it has received the root certificate [1638338556.709101][189523:189528] CHIP:CTL: Sending operational certificate chain to the device [1638338556.709201][189523:189528] CHIP:DMG: ICR moving to [AddingComm] [1638338556.709277][189523:189528] CHIP:DMG: ICR moving to [AddedComma] [1638338556.709503][189523:189528] CHIP:IN: Prepared encrypted message 0xffffa77ed230 to 0x0000000000BC5C01 (1) of type 0x8 and protocolId (0, 1) on exchange 35150i with MessageCounter:6. [1638338556.709600][189523:189528] CHIP:IN: Sending encrypted msg 0xffffa77ed230 with MessageCounter:6 to 0x0000000000BC5C01 (1) at monotonic time: 99495866 msec [1638338556.709801][189523:189528] CHIP:DMG: ICR moving to [CommandSen] [1638338556.709870][189523:189528] CHIP:CTL: Sent operational certificate to the device [1638338556.709950][189523:189528] CHIP:DMG: ICR moving to [AwaitingDe] [1638338561.971796][189523:189528] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:6 on exchange 35150i [1638338561.971945][189523:189528] CHIP:DMG: InvokeResponseMessage = [1638338561.972008][189523:189528] CHIP:DMG: { [1638338561.972067][189523:189528] CHIP:DMG: suppressResponse = false, [1638338561.972129][189523:189528] CHIP:DMG: InvokeResponses = [1638338561.972191][189523:189528] CHIP:DMG: [ [1638338561.972251][189523:189528] CHIP:DMG: InvokeResponseIB = [1638338561.972362][189523:189528] CHIP:DMG: { [1638338561.972442][189523:189528] CHIP:DMG: CommandDataIB = [1638338561.972521][189523:189528] CHIP:DMG: { [1638338561.972602][189523:189528] CHIP:DMG: CommandPathIB = [1638338561.972687][189523:189528] CHIP:DMG: { [1638338561.972781][189523:189528] CHIP:DMG: EndpointId = 0x0, [1638338561.972877][189523:189528] CHIP:DMG: ClusterId = 0x3e, [1638338561.972970][189523:189528] CHIP:DMG: CommandId = 0x8, [1638338561.973051][189523:189528] CHIP:DMG: }, [1638338561.973140][189523:189528] CHIP:DMG: [1638338561.973216][189523:189528] CHIP:DMG: CommandData = [1638338561.973304][189523:189528] CHIP:DMG: { [1638338561.973396][189523:189528] CHIP:DMG: 0x0 = 0, [1638338561.973490][189523:189528] CHIP:DMG: 0x1 = 1, [1638338561.973587][189523:189528] CHIP:DMG: 0x2 = "", [1638338561.973679][189523:189528] CHIP:DMG: }, [1638338561.973757][189523:189528] CHIP:DMG: }, [1638338561.973852][189523:189528] CHIP:DMG: [1638338561.973920][189523:189528] CHIP:DMG: }, [1638338561.974002][189523:189528] CHIP:DMG: [1638338561.974061][189523:189528] CHIP:DMG: ], [1638338561.974135][189523:189528] CHIP:DMG: [1638338561.974189][189523:189528] CHIP:DMG: }, [1638338561.974303][189523:189528] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008 [1638338561.974384][189523:189528] CHIP:ZCL: NOCResponse: [1638338561.974437][189523:189528] CHIP:ZCL: StatusCode: 0 [1638338561.974487][189523:189528] CHIP:ZCL: FabricIndex: 1 [1638338561.974536][189523:189528] CHIP:ZCL: DebugText: [1638338561.974592][189523:189528] CHIP:CTL: Device returned status 0 on receiving the NOC [1638338561.974646][189523:189528] CHIP:CTL: Operational credentials provisioned on device 0xffffac4c9808 [1638338561.974725][189523:189528] CHIP:TOO: Secure Pairing Success [1638338561.976348][189523:189528] CHIP:TOO: Pairing Success [1638338561.976493][189523:189528] CHIP:DMG: ICR moving to [AddingComm] [1638338561.976568][189523:189528] CHIP:DMG: ICR moving to [AddedComma] [1638338561.976757][189523:189528] CHIP:IN: Prepared encrypted message 0xffffa77ecf90 to 0x0000000000BC5C01 (1) of type 0x8 and protocolId (0, 1) on exchange 35151i with MessageCounter:7. [1638338561.976856][189523:189528] CHIP:IN: Sending encrypted msg 0xffffa77ecf90 with MessageCounter:7 to 0x0000000000BC5C01 (1) at monotonic time: 99501133 msec [1638338561.977083][189523:189528] CHIP:DMG: ICR moving to [CommandSen] [1638338561.977183][189523:189528] CHIP:DMG: ICR moving to [AwaitingDe] [1638338562.656091][189523:189528] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:7 on exchange 35151i [1638338562.656214][189523:189528] CHIP:DMG: InvokeResponseMessage = [1638338562.656271][189523:189528] CHIP:DMG: { [1638338562.656325][189523:189528] CHIP:DMG: suppressResponse = false, [1638338562.656379][189523:189528] CHIP:DMG: InvokeResponses = [1638338562.656434][189523:189528] CHIP:DMG: [ [1638338562.656486][189523:189528] CHIP:DMG: InvokeResponseIB = [1638338562.656548][189523:189528] CHIP:DMG: { [1638338562.656607][189523:189528] CHIP:DMG: CommandDataIB = [1638338562.656691][189523:189528] CHIP:DMG: { [1638338562.656756][189523:189528] CHIP:DMG: CommandPathIB = [1638338562.656841][189523:189528] CHIP:DMG: { [1638338562.656928][189523:189528] CHIP:DMG: EndpointId = 0x0, [1638338562.657011][189523:189528] CHIP:DMG: ClusterId = 0x31, [1638338562.657094][189523:189528] CHIP:DMG: CommandId = 0x3, [1638338562.657175][189523:189528] CHIP:DMG: }, [1638338562.657262][189523:189528] CHIP:DMG: [1638338562.657336][189523:189528] CHIP:DMG: CommandData = [1638338562.657413][189523:189528] CHIP:DMG: { [1638338562.657495][189523:189528] CHIP:DMG: 0x0 = 0, [1638338562.657581][189523:189528] CHIP:DMG: 0x1 = "", [1638338562.657662][189523:189528] CHIP:DMG: }, [1638338562.657736][189523:189528] CHIP:DMG: }, [1638338562.657924][189523:189528] CHIP:DMG: [1638338562.657995][189523:189528] CHIP:DMG: }, [1638338562.658068][189523:189528] CHIP:DMG: [1638338562.658120][189523:189528] CHIP:DMG: ], [1638338562.658184][189523:189528] CHIP:DMG: [1638338562.658232][189523:189528] CHIP:DMG: }, [1638338562.658331][189523:189528] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 [1638338562.658403][189523:189528] CHIP:ZCL: AddWiFiNetworkResponse: [1638338562.658450][189523:189528] CHIP:ZCL: errorCode: 0 [1638338562.658493][189523:189528] CHIP:ZCL: debugText: [1638338562.658543][189523:189528] CHIP:TOO: AddNetworkResponse [1638338562.658629][189523:189528] CHIP:DMG: ICR moving to [AddingComm] [1638338562.658691][189523:189528] CHIP:DMG: ICR moving to [AddedComma] [1638338562.658854][189523:189528] CHIP:IN: Prepared encrypted message 0xffffa77ed160 to 0x0000000000BC5C01 (1) of type 0x8 and protocolId (0, 1) on exchange 35152i with MessageCounter:8. [1638338562.658938][189523:189528] CHIP:IN: Sending encrypted msg 0xffffa77ed160 with MessageCounter:8 to 0x0000000000BC5C01 (1) at monotonic time: 99501815 msec [1638338562.659006][189523:189528] CHIP:DMG: ICR moving to [CommandSen] [1638338562.659078][189523:189528] CHIP:DMG: ICR moving to [AwaitingDe] [1638338570.504569][189523:189528] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8 on exchange 35152i [1638338570.504702][189523:189528] CHIP:DMG: InvokeResponseMessage = [1638338570.504767][189523:189528] CHIP:DMG: { [1638338570.504826][189523:189528] CHIP:DMG: suppressResponse = false, [1638338570.504888][189523:189528] CHIP:DMG: InvokeResponses = [1638338570.504951][189523:189528] CHIP:DMG: [ [1638338570.505011][189523:189528] CHIP:DMG: InvokeResponseIB = [1638338570.505083][189523:189528] CHIP:DMG: { [1638338570.505148][189523:189528] CHIP:DMG: CommandDataIB = [1638338570.505227][189523:189528] CHIP:DMG: { [1638338570.505301][189523:189528] CHIP:DMG: CommandPathIB = [1638338570.505384][189523:189528] CHIP:DMG: { [1638338570.505477][189523:189528] CHIP:DMG: EndpointId = 0x0, [1638338570.505565][189523:189528] CHIP:DMG: ClusterId = 0x31, [1638338570.505657][189523:189528] CHIP:DMG: CommandId = 0xd, [1638338570.505746][189523:189528] CHIP:DMG: }, [1638338570.505841][189523:189528] CHIP:DMG: [1638338570.505916][189523:189528] CHIP:DMG: CommandData = [1638338570.505997][189523:189528] CHIP:DMG: { [1638338570.506088][189523:189528] CHIP:DMG: 0x0 = 0, [1638338570.506176][189523:189528] CHIP:DMG: 0x1 = "", [1638338570.506267][189523:189528] CHIP:DMG: }, [1638338570.506352][189523:189528] CHIP:DMG: }, [1638338570.506440][189523:189528] CHIP:DMG: [1638338570.506507][189523:189528] CHIP:DMG: }, [1638338570.506590][189523:189528] CHIP:DMG: [1638338570.506649][189523:189528] CHIP:DMG: ], [1638338570.506722][189523:189528] CHIP:DMG: [1638338570.506776][189523:189528] CHIP:DMG: }, [1638338570.506887][189523:189528] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_000D [1638338570.506966][189523:189528] CHIP:ZCL: EnableNetworkResponse: [1638338570.507018][189523:189528] CHIP:ZCL: errorCode: 0 [1638338570.507069][189523:189528] CHIP:ZCL: debugText: [1638338570.507127][189523:189528] CHIP:TOO: EnableNetworkResponse [1638338570.507192][189523:189528] CHIP:TOO: Mdns: Updating NodeId: bc5c01 Compressed FabricId: e83c1030b722e1ef ... [1638338570.507798][189523:189528] CHIP:DIS: Attempt to mDNS broadcast failed: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPoint.cpp:1039: OS Error 0x02000065: Network is unreachable [1638338570.508520][189523:189528] CHIP:DIS: Attempt to mDNS broadcast failed: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPoint.cpp:1039: OS Error 0x02000065: Network is unreachable [1638338570.508680][189523:189528] CHIP:DMG: ICR moving to [AwaitingDe] [1638338570.520706][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.520753][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.520778][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.520803][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.520827][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.521419][189523:189528] CHIP:IN: Generating DestinationID. Fabric ID 0x0000000000000001, Dest node ID 0x0000000000BC5C01, Random data [1638338570.521570][189523:189528] CHIP:IN: 0xe1, 0x61, 0x91, 0x7a, 0x63, 0x87, 0x69, 0xa4, [1638338570.521599][189523:189528] CHIP:IN: 0xbf, 0x76, 0x61, 0x87, 0xe2, 0xcf, 0xc0, 0x1d, [1638338570.521624][189523:189528] CHIP:IN: 0xf2, 0x92, 0xc4, 0x20, 0x05, 0x0a, 0xcb, 0x9f, [1638338570.521648][189523:189528] CHIP:IN: 0x34, 0x34, 0x81, 0xed, 0x3c, 0xd7, 0xca, 0xa1, [1638338570.521670][189523:189528] CHIP:IN: Root pubkey [1638338570.521710][189523:189528] CHIP:IN: 0x04, 0x3c, 0xce, 0x8a, 0x2c, 0x16, 0x94, 0x9e, [1638338570.521735][189523:189528] CHIP:IN: 0x36, 0x3c, 0x8f, 0xdd, 0x1d, 0x10, 0xc4, 0x52, [1638338570.521759][189523:189528] CHIP:IN: 0x6d, 0x55, 0xe7, 0x15, 0xc6, 0x70, 0xc3, 0x38, [1638338570.521783][189523:189528] CHIP:IN: 0x2d, 0xef, 0xe2, 0xbf, 0x96, 0x7d, 0x13, 0x05, [1638338570.521808][189523:189528] CHIP:IN: 0x8b, 0x49, 0x94, 0x4b, 0xd7, 0x0b, 0xa8, 0x88, [1638338570.521843][189523:189528] CHIP:IN: 0xf3, 0x2a, 0x91, 0x13, 0x0e, 0xd9, 0x47, 0x06, [1638338570.521869][189523:189528] CHIP:IN: 0x36, 0x58, 0x6a, 0x3b, 0xcd, 0x5a, 0x0d, 0x24, [1638338570.521892][189523:189528] CHIP:IN: 0xf8, 0x97, 0x46, 0x93, 0xeb, 0x96, 0x18, 0xea, [1638338570.521914][189523:189528] CHIP:IN: 0xa2, [1638338570.521935][189523:189528] CHIP:IN: IPK [1638338570.521960][189523:189528] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, [1638338570.521984][189523:189528] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, [1638338570.522022][189523:189528] CHIP:IN: Generated DestinationID output [1638338570.522061][189523:189528] CHIP:IN: 0x01, 0x7d, 0x59, 0xe8, 0xab, 0xd7, 0x69, 0x32, [1638338570.522085][189523:189528] CHIP:IN: 0x79, 0x76, 0x4a, 0x9a, 0xe4, 0x69, 0x6b, 0xdf, [1638338570.522109][189523:189528] CHIP:IN: 0x84, 0xa2, 0xa5, 0x51, 0x3c, 0xd6, 0x82, 0x77, [1638338570.522132][189523:189528] CHIP:IN: 0xba, 0x7f, 0xe6, 0xe9, 0xe1, 0xce, 0xd5, 0x48, [1638338570.522205][189523:189528] CHIP:IN: Prepared plaintext message 0xaaaaf369a998 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 35153i with MessageCounter:2664102296. [1638338570.522264][189523:189528] CHIP:IN: Sending plaintext msg 0xaaaaf369a998 with MessageCounter:2664102296 to 0x0000000000000000 at monotonic time: 99509678 msec [1638338570.522412][189523:189528] CHIP:SC: Sent Sigma1 msg [1638338570.522449][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.522484][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.522638][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.522678][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.522809][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.522841][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.522866][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.522892][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.522926][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.522955][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.523186][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.523230][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.523271][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.523310][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.523346][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.523381][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.523424][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.523514][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.523659][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.523700][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.523739][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.523778][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.523815][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.523848][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.523895][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.523940][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.524089][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.524131][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.524170][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.524208][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.524244][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.524277][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.524320][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.524362][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.524596][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.524636][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.524674][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.524712][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.524748][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.524782][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.524824][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.524866][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.525135][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.525175][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.525213][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.525251][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.525287][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.525320][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.525361][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.525402][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.525600][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.525640][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.525678][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.525716][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.525752][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.525785][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.525827][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.525869][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.526067][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.526108][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.526147][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.526185][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.526221][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.526254][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.526296][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.526338][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.550403][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.550479][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.550541][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.550600][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.550655][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.550704][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.550775][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.550841][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.551061][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.551145][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.551208][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.551264][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.551318][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.551391][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.551492][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.551561][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.551769][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.551829][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.551912][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.551971][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.552024][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.552074][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.552159][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.552222][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.552419][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.552481][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.552540][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.552621][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.552676][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.552726][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.552809][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.552878][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.553078][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.553138][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.553195][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.553272][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.553330][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.553380][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.553442][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.553527][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.557039][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.557088][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.557129][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.557168][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.557204][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.557238][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.557286][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.557346][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.557475][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.557531][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.557570][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.557609][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.557660][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.557694][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.557737][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.557793][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.557913][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.557968][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.558007][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.558045][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.558096][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.558130][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.558172][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.558229][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.558348][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.558402][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.558442][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.558480][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.558531][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.558565][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.558607][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.558648][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.558786][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.558840][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.558879][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.558918][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.558968][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.559002][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.559043][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.559099][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.562699][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.562747][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.562789][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.562827][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.562863][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.562896][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.562941][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.563000][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.563126][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.563183][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.563221][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.563260][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.563311][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.563346][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.563388][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.563445][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.563618][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.563674][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.563712][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.563750][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.563800][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.563835][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.563877][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.563933][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338570.564053][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338570.564107][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338570.564145][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338570.564319][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338570.564372][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338570.564407][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338570.564490][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338570.564553][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338571.851302][189523:189528] CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:659506923 on exchange 35153i [1638338571.851506][189523:189528] CHIP:EM: Rxd Ack; Removing MessageCounter:2664102296 from Retrans Table on exchange 35153i [1638338571.851572][189523:189528] CHIP:EM: Removed CHIP MessageCounter:2664102296 from RetransTable on exchange 35153i [1638338571.851665][189523:189528] CHIP:SC: Received Sigma2 msg [1638338571.851747][189523:189528] CHIP:SC: Peer assigned session session ID 2 [1638338571.857890][189523:189528] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey [1638338571.857955][189523:189528] CHIP:IN: 0x04, 0x3c, 0xce, 0x8a, 0x2c, 0x16, 0x94, 0x9e, [1638338571.857992][189523:189528] CHIP:IN: 0x36, 0x3c, 0x8f, 0xdd, 0x1d, 0x10, 0xc4, 0x52, [1638338571.858028][189523:189528] CHIP:IN: 0x6d, 0x55, 0xe7, 0x15, 0xc6, 0x70, 0xc3, 0x38, [1638338571.858063][189523:189528] CHIP:IN: 0x2d, 0xef, 0xe2, 0xbf, 0x96, 0x7d, 0x13, 0x05, [1638338571.858097][189523:189528] CHIP:IN: 0x8b, 0x49, 0x94, 0x4b, 0xd7, 0x0b, 0xa8, 0x88, [1638338571.858131][189523:189528] CHIP:IN: 0xf3, 0x2a, 0x91, 0x13, 0x0e, 0xd9, 0x47, 0x06, [1638338571.858166][189523:189528] CHIP:IN: 0x36, 0x58, 0x6a, 0x3b, 0xcd, 0x5a, 0x0d, 0x24, [1638338571.858200][189523:189528] CHIP:IN: 0xf8, 0x97, 0x46, 0x93, 0xeb, 0x96, 0x18, 0xea, [1638338571.858230][189523:189528] CHIP:IN: 0xa2, [1638338571.858403][189523:189528] CHIP:IN: Generated compressed fabric ID [1638338571.858449][189523:189528] CHIP:IN: 0xe8, 0x3c, 0x10, 0x30, 0xb7, 0x22, 0xe1, 0xef, [1638338571.859871][189523:189528] CHIP:SC: Sending Sigma3 [1638338571.860412][189523:189528] CHIP:EM: Piggybacking Ack for MessageCounter:659506923 on exchange: 35153i [1638338571.860483][189523:189528] CHIP:IN: Prepared plaintext message 0xaaaaf369a998 to 0x0000000000000000 (0) of type 0x32 and protocolId (0, 0) on exchange 35153i with MessageCounter:2664102297. [1638338571.860541][189523:189528] CHIP:IN: Sending plaintext msg 0xaaaaf369a998 with MessageCounter:2664102297 to 0x0000000000000000 at monotonic time: 99511017 msec [1638338571.860737][189523:189528] CHIP:SC: Sent Sigma3 msg [1638338571.861016][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338571.861058][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338571.861098][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338571.861134][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338571.861167][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338571.861198][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338571.861246][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338571.861305][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338571.861438][189523:189528] CHIP:DIS: Discovered node without a pending query [1638338571.861475][189523:189528] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338571.861511][189523:189528] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338571.861545][189523:189528] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338571.861591][189523:189528] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338571.861622][189523:189528] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338571.861661][189523:189528] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338571.861713][189523:189528] CHIP:TOO: OnAddressUpdateComplete: bc5c01: ../../examples/chip-tool/third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:499: Success [1638338574.153843][189523:189528] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:659506924 on exchange 35153i [1638338574.153964][189523:189528] CHIP:EM: Rxd Ack; Removing MessageCounter:2664102297 from Retrans Table on exchange 35153i [1638338574.154006][189523:189528] CHIP:EM: Removed CHIP MessageCounter:2664102297 from RetransTable on exchange 35153i [1638338574.154068][189523:189528] CHIP:SC: Success status report received. Session was established [1638338574.154109][189523:189528] CHIP:IN: New secure session created for device 0x0000000000BC5C01, key 2!! [1638338574.154214][189523:189528] CHIP:CTL: OnNewConnection was called for unknown device, ignoring it. [1638338574.154261][189523:189528] CHIP:TOO: Device commissioning completed with success [1638338574.154356][189523:189528] CHIP:EM: Sending Standalone Ack for MessageCounter:659506924 on exchange 35153i [1638338574.154413][189523:189528] CHIP:IN: Prepared plaintext message 0xffffa77ed980 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 35153i with MessageCounter:2664102298. [1638338574.154467][189523:189528] CHIP:IN: Sending plaintext msg 0xffffa77ed980 with MessageCounter:2664102298 to 0x0000000000000000 at monotonic time: 99513311 msec [1638338574.154637][189523:189528] CHIP:EM: Flushed pending ack for MessageCounter:659506924 on exchange 35153i [1638338574.154978][189523:189523] CHIP:CTL: Shutting down the commissioner [1638338574.155149][189523:189523] CHIP:CTL: Shutting down the controller [1638338574.156061][189523:189523] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1638338574.156424][189523:189523] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-8zK8SE) [1638338574.157307][189523:189523] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1638338574.157387][189523:189523] CHIP:DL: NVS set: chip-counters/total-operational-hours = 2 (0x2) [1638338574.157425][189523:189523] CHIP:DL: Inet Layer shutdown [1638338574.157457][189523:189523] CHIP:DL: BLE shutdown [1638338574.157495][189523:189523] CHIP:IN: Clearing BLE pending packets. [1638338574.157623][189523:189523] CHIP:BLE: Auto-closing end point's BLE connection. [1638338574.157664][189523:189523] CHIP:DL: Closing BLE GATT connection (con 0xffff9c030120) [1638338574.157974][189523:189526] CHIP:DL: BluezDisconnect peer=D4:4D:A4:A0:02:A5 [1638338574.159004][189523:189523] CHIP:DL: System Layer shutdown [1638338574.159306][189523:189523] CHIP:CSL: System wake event notify failed: ../../examples/chip-tool/third_party/connectedhomeip/src/system/WakeEvent.cpp:116: OS Error 0x02000009: Bad file descriptor [1638338574.159510][189523:189523] CHIP:CSL: System wake event notify failed: ../../examples/chip-tool/third_party/connectedhomeip/src/system/WakeEvent.cpp:116: OS Error 0x02000009: Bad file descriptor [1638338574.164529][189523:189523] CHIP:SPT: VerifyOrDie failure at ../../examples/chip-tool/third_party/connectedhomeip/src/inet/InetLayer.h:100: sEndPointPool.Allocated() == 0 Aborted ubuntu@matter-te-7:~/temp/connectedhomeip$ sudo out/chip-tool/chip-tool basic read vendor-name 12344321 0 [1638338578.839390][189533:189533] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-atojgi) [1638338578.840086][189533:189533] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1638338578.840146][189533:189533] CHIP:DL: NVS set: chip-counters/reboot-count = 109 (0x6D) [1638338578.840946][189533:189533] CHIP:DL: Got Ethernet interface: eth0 [1638338578.841466][189533:189533] CHIP:DL: Found the primary Ethernet interface:eth0 [1638338578.842262][189533:189533] CHIP:DL: Got WiFi interface: wlan0 [1638338578.842349][189533:189533] CHIP:DL: Failed to reset WiFi statistic counts [1638338578.842417][189533:189533] CHIP:IN: UDP::Init bind&listen port=5542 [1638338578.842529][189533:189533] CHIP:IN: UDP::Init bound to port=5542 [1638338578.842556][189533:189533] CHIP:IN: UDP::Init bind&listen port=5542 [1638338578.842648][189533:189533] CHIP:IN: UDP::Init bound to port=5542 [1638338578.842674][189533:189533] CHIP:IN: TransportMgr initialized [1638338578.842717][189533:189533] CHIP:DIS: Init fabric pairing table with server storage [1638338578.843100][189533:189533] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Qn71lS) [1638338578.843975][189533:189533] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1638338578.844050][189533:189533] CHIP:DL: NVS set: chip-counters/GlobalMCTR = 109000 (0x1A9C8) [1638338578.844213][189533:189533] CHIP:CTL: System State Initialized... [1638338578.847704][189533:189533] CHIP:CTL: Generating NOC [1638338578.848288][189533:189533] CHIP:CTL: Generating ICAC [1638338578.851995][189533:189533] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPoint.cpp:1395: Inet Error 0x00000110: Address not found [1638338578.855614][189533:189533] CHIP:ZCL: Using ZAP configuration... [1638338578.856489][189533:189533] CHIP:DIS: Verifying the received credentials [1638338578.859439][189533:189533] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey [1638338578.859510][189533:189533] CHIP:IN: 0x04, 0x3c, 0xce, 0x8a, 0x2c, 0x16, 0x94, 0x9e, [1638338578.859534][189533:189533] CHIP:IN: 0x36, 0x3c, 0x8f, 0xdd, 0x1d, 0x10, 0xc4, 0x52, [1638338578.859557][189533:189533] CHIP:IN: 0x6d, 0x55, 0xe7, 0x15, 0xc6, 0x70, 0xc3, 0x38, [1638338578.859580][189533:189533] CHIP:IN: 0x2d, 0xef, 0xe2, 0xbf, 0x96, 0x7d, 0x13, 0x05, [1638338578.859604][189533:189533] CHIP:IN: 0x8b, 0x49, 0x94, 0x4b, 0xd7, 0x0b, 0xa8, 0x88, [1638338578.859626][189533:189533] CHIP:IN: 0xf3, 0x2a, 0x91, 0x13, 0x0e, 0xd9, 0x47, 0x06, [1638338578.859649][189533:189533] CHIP:IN: 0x36, 0x58, 0x6a, 0x3b, 0xcd, 0x5a, 0x0d, 0x24, [1638338578.859671][189533:189533] CHIP:IN: 0xf8, 0x97, 0x46, 0x93, 0xeb, 0x96, 0x18, 0xea, [1638338578.859691][189533:189533] CHIP:IN: 0xa2, [1638338578.859747][189533:189533] CHIP:IN: Generated compressed fabric ID [1638338578.859775][189533:189533] CHIP:IN: 0xe8, 0x3c, 0x10, 0x30, 0xb7, 0x22, 0xe1, 0xef, [1638338578.859808][189533:189533] CHIP:DIS: Added new fabric at index: 1, Initialized: 1 [1638338578.859831][189533:189533] CHIP:DIS: Assigned compressed fabric ID: 0xE83C1030B722E1EF, node ID: 0x000000000001B669 [1638338578.859853][189533:189533] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xE83C1030B722E1EF [1638338578.859986][189533:189533] CHIP:IN: UDP::Init bind&listen port=5550 [1638338578.860128][189533:189533] CHIP:IN: UDP::Init bound to port=5550 [1638338578.860156][189533:189533] CHIP:IN: UDP::Init bind&listen port=5550 [1638338578.860246][189533:189533] CHIP:IN: UDP::Init bound to port=5550 [1638338578.860269][189533:189533] CHIP:IN: TransportMgr initialized [1638338578.860547][189533:189538] CHIP:DL: CHIP task running [1638338578.860659][189533:189538] CHIP:TOO: Sending command to node 0xbc5c01 [1638338578.861162][189533:189538] CHIP:DIS: Attempt to mDNS broadcast failed: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPoint.cpp:1039: OS Error 0x02000065: Network is unreachable [1638338578.861579][189533:189538] CHIP:DIS: Attempt to mDNS broadcast failed: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPoint.cpp:1039: OS Error 0x02000065: Network is unreachable [1638338578.905127][189533:189538] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338578.905226][189533:189538] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338578.905290][189533:189538] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338578.905348][189533:189538] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338578.905406][189533:189538] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338578.906614][189533:189538] CHIP:IN: Generating DestinationID. Fabric ID 0x0000000000000001, Dest node ID 0x0000000000BC5C01, Random data [1638338578.906709][189533:189538] CHIP:IN: 0x13, 0x51, 0xea, 0xb4, 0x0b, 0x57, 0x6c, 0xd2, [1638338578.906771][189533:189538] CHIP:IN: 0x33, 0x06, 0x11, 0xa2, 0x92, 0xf9, 0xf8, 0x8e, [1638338578.906830][189533:189538] CHIP:IN: 0xaf, 0xad, 0x5b, 0x12, 0x3a, 0x59, 0x32, 0xb0, [1638338578.906888][189533:189538] CHIP:IN: 0x51, 0x55, 0x62, 0xe2, 0x02, 0xc3, 0x83, 0x05, [1638338578.906941][189533:189538] CHIP:IN: Root pubkey [1638338578.906993][189533:189538] CHIP:IN: 0x04, 0x3c, 0xce, 0x8a, 0x2c, 0x16, 0x94, 0x9e, [1638338578.907043][189533:189538] CHIP:IN: 0x36, 0x3c, 0x8f, 0xdd, 0x1d, 0x10, 0xc4, 0x52, [1638338578.907101][189533:189538] CHIP:IN: 0x6d, 0x55, 0xe7, 0x15, 0xc6, 0x70, 0xc3, 0x38, [1638338578.907158][189533:189538] CHIP:IN: 0x2d, 0xef, 0xe2, 0xbf, 0x96, 0x7d, 0x13, 0x05, [1638338578.907217][189533:189538] CHIP:IN: 0x8b, 0x49, 0x94, 0x4b, 0xd7, 0x0b, 0xa8, 0x88, [1638338578.907275][189533:189538] CHIP:IN: 0xf3, 0x2a, 0x91, 0x13, 0x0e, 0xd9, 0x47, 0x06, [1638338578.907332][189533:189538] CHIP:IN: 0x36, 0x58, 0x6a, 0x3b, 0xcd, 0x5a, 0x0d, 0x24, [1638338578.907389][189533:189538] CHIP:IN: 0xf8, 0x97, 0x46, 0x93, 0xeb, 0x96, 0x18, 0xea, [1638338578.907440][189533:189538] CHIP:IN: 0xa2, [1638338578.907540][189533:189538] CHIP:IN: IPK [1638338578.907602][189533:189538] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, [1638338578.907661][189533:189538] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, [1638338578.907743][189533:189538] CHIP:IN: Generated DestinationID output [1638338578.907808][189533:189538] CHIP:IN: 0x3a, 0x50, 0x34, 0x1d, 0xb9, 0xd2, 0xcb, 0x4a, [1638338578.907866][189533:189538] CHIP:IN: 0xb0, 0x5c, 0xd3, 0x62, 0xd0, 0x51, 0x23, 0xd7, [1638338578.907923][189533:189538] CHIP:IN: 0xe7, 0x94, 0x30, 0xde, 0x98, 0x81, 0xad, 0x4b, [1638338578.907980][189533:189538] CHIP:IN: 0x53, 0xfa, 0x8c, 0x44, 0xcb, 0xe9, 0x1b, 0x80, [1638338578.908107][189533:189538] CHIP:IN: Prepared plaintext message 0xaaab0fb309d8 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 19287i with MessageCounter:2224725261. [1638338578.908206][189533:189538] CHIP:IN: Sending plaintext msg 0xaaab0fb309d8 with MessageCounter:2224725261 to 0x0000000000000000 at monotonic time: 99518064 msec [1638338578.908471][189533:189538] CHIP:SC: Sent Sigma1 msg [1638338578.908548][189533:189538] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338578.908929][189533:189538] CHIP:DIS: Discovered node without a pending query [1638338578.908996][189533:189538] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01 [1638338578.909060][189533:189538] CHIP:DIS: Addr 0: [fe80::d64d:a4ff:fea0:2a4]:5540 [1638338578.909122][189533:189538] CHIP:DIS: Addr 1: [2001:db6:1:0:d64d:a4ff:fea0:2a4]:5540 [1638338578.909178][189533:189538] CHIP:DIS: Addr 2: [192.168.1.111]:5540 [1638338578.909233][189533:189538] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01 [1638338578.909300][189533:189538] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01 [1638338580.159130][189533:189538] CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:659506925 on exchange 19287i [1638338580.159278][189533:189538] CHIP:EM: Rxd Ack; Removing MessageCounter:2224725261 from Retrans Table on exchange 19287i [1638338580.159343][189533:189538] CHIP:EM: Removed CHIP MessageCounter:2224725261 from RetransTable on exchange 19287i [1638338580.159428][189533:189538] CHIP:SC: Received Sigma2 msg [1638338580.159554][189533:189538] CHIP:SC: Peer assigned session session ID 3 [1638338580.165407][189533:189538] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey [1638338580.165472][189533:189538] CHIP:IN: 0x04, 0x3c, 0xce, 0x8a, 0x2c, 0x16, 0x94, 0x9e, [1638338580.165577][189533:189538] CHIP:IN: 0x36, 0x3c, 0x8f, 0xdd, 0x1d, 0x10, 0xc4, 0x52, [1638338580.165616][189533:189538] CHIP:IN: 0x6d, 0x55, 0xe7, 0x15, 0xc6, 0x70, 0xc3, 0x38, [1638338580.165651][189533:189538] CHIP:IN: 0x2d, 0xef, 0xe2, 0xbf, 0x96, 0x7d, 0x13, 0x05, [1638338580.165686][189533:189538] CHIP:IN: 0x8b, 0x49, 0x94, 0x4b, 0xd7, 0x0b, 0xa8, 0x88, [1638338580.165721][189533:189538] CHIP:IN: 0xf3, 0x2a, 0x91, 0x13, 0x0e, 0xd9, 0x47, 0x06, [1638338580.165756][189533:189538] CHIP:IN: 0x36, 0x58, 0x6a, 0x3b, 0xcd, 0x5a, 0x0d, 0x24, [1638338580.165790][189533:189538] CHIP:IN: 0xf8, 0x97, 0x46, 0x93, 0xeb, 0x96, 0x18, 0xea, [1638338580.165822][189533:189538] CHIP:IN: 0xa2, [1638338580.165891][189533:189538] CHIP:IN: Generated compressed fabric ID [1638338580.165932][189533:189538] CHIP:IN: 0xe8, 0x3c, 0x10, 0x30, 0xb7, 0x22, 0xe1, 0xef, [1638338580.167186][189533:189538] CHIP:SC: Sending Sigma3 [1638338580.167713][189533:189538] CHIP:EM: Piggybacking Ack for MessageCounter:659506925 on exchange: 19287i [1638338580.167783][189533:189538] CHIP:IN: Prepared plaintext message 0xaaab0fb309d8 to 0x0000000000000000 (0) of type 0x32 and protocolId (0, 0) on exchange 19287i with MessageCounter:2224725262. [1638338580.167841][189533:189538] CHIP:IN: Sending plaintext msg 0xaaab0fb309d8 with MessageCounter:2224725262 to 0x0000000000000000 at monotonic time: 99519324 msec [1638338580.168037][189533:189538] CHIP:SC: Sent Sigma3 msg [1638338582.484997][189533:189538] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:659506926 on exchange 19287i [1638338582.485146][189533:189538] CHIP:EM: Rxd Ack; Removing MessageCounter:2224725262 from Retrans Table on exchange 19287i [1638338582.485209][189533:189538] CHIP:EM: Removed CHIP MessageCounter:2224725262 from RetransTable on exchange 19287i [1638338582.485299][189533:189538] CHIP:SC: Success status report received. Session was established [1638338582.485367][189533:189538] CHIP:IN: New secure session created for device 0x0000000000BC5C01, key 3!! [1638338582.485520][189533:189538] CHIP:CTL: OnNewConnection was called for unknown device, ignoring it. [1638338582.485594][189533:189538] CHIP:TOO: Sending cluster (0x0028) command (0x00) on endpoint 0 [1638338582.485671][189533:189538] CHIP:DMG: SendReadRequest: Client[0] [ INIT] [1638338582.485863][189533:189538] CHIP:IN: Prepared encrypted message 0xaaab0fb309d8 to 0x0000000000BC5C01 (1) of type 0x2 and protocolId (0, 1) on exchange 19288i with MessageCounter:1. [1638338582.485957][189533:189538] CHIP:IN: Sending encrypted msg 0xaaab0fb309d8 with MessageCounter:1 to 0x0000000000BC5C01 (1) at monotonic time: 99521642 msec [1638338582.486220][189533:189538] CHIP:DMG: Client[0] moving to [AwaitingInitialReport] [1638338582.486338][189533:189538] CHIP:CTL: Device connected callback with null pairing delegate. Ignoring [1638338582.486404][189533:189538] CHIP:EM: Sending Standalone Ack for MessageCounter:659506926 on exchange 19287i [1638338582.486481][189533:189538] CHIP:IN: Prepared plaintext message 0xffff84824980 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 19287i with MessageCounter:2224725263. [1638338582.486563][189533:189538] CHIP:IN: Sending plaintext msg 0xffff84824980 with MessageCounter:2224725263 to 0x0000000000000000 at monotonic time: 99521643 msec [1638338582.486748][189533:189538] CHIP:EM: Flushed pending ack for MessageCounter:659506926 on exchange 19287i [1638338582.605947][189533:189538] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:1 on exchange 19288i [1638338582.606053][189533:189538] CHIP:EM: Rxd Ack; Removing MessageCounter:1 from Retrans Table on exchange 19288i [1638338582.606107][189533:189538] CHIP:EM: Removed CHIP MessageCounter:1 from RetransTable on exchange 19288i [1638338582.606193][189533:189538] CHIP:DMG: ReportDataMessage = [1638338582.606249][189533:189538] CHIP:DMG: { [1638338582.606296][189533:189538] CHIP:DMG: AttributeReportIBs = [1638338582.606352][189533:189538] CHIP:DMG: [ [1638338582.606404][189533:189538] CHIP:DMG: AttributeReportIB = [1638338582.606475][189533:189538] CHIP:DMG: { [1638338582.606532][189533:189538] CHIP:DMG: AttributeDataIB = [1638338582.606599][189533:189538] CHIP:DMG: { [1638338582.606665][189533:189538] CHIP:DMG: AttributePathIB = [1638338582.606743][189533:189538] CHIP:DMG: { [1638338582.606816][189533:189538] CHIP:DMG: Endpoint = 0x0, [1638338582.606892][189533:189538] CHIP:DMG: Cluster = 0x28, [1638338582.606966][189533:189538] CHIP:DMG: Attribute = 0x0000_0001, [1638338582.607037][189533:189538] CHIP:DMG: } [1638338582.607115][189533:189538] CHIP:DMG: [1638338582.607198][189533:189538] CHIP:DMG: Data = "TEST_VENDOR", [1638338582.607285][189533:189538] CHIP:DMG: DataVersion = 0x0, [1638338582.607370][189533:189538] CHIP:DMG: }, [1638338582.607513][189533:189538] CHIP:DMG: [1638338582.607591][189533:189538] CHIP:DMG: }, [1638338582.607679][189533:189538] CHIP:DMG: [1638338582.607741][189533:189538] CHIP:DMG: ], [1638338582.607817][189533:189538] CHIP:DMG: [1638338582.607877][189533:189538] CHIP:DMG: SuppressResponse = true, [1638338582.607936][189533:189538] CHIP:DMG: } [1638338582.608125][189533:189538] CHIP:ZCL: ReadAttributesResponse: [1638338582.608182][189533:189538] CHIP:ZCL: ClusterId: 0x0000_0028 [1638338582.608239][189533:189538] CHIP:ZCL: attributeId: 0x0000_0001 [1638338582.608292][189533:189538] CHIP:ZCL: status: Success (0x0000) [1638338582.608344][189533:189538] CHIP:ZCL: attribute TLV Type: 0x0c [1638338582.608400][189533:189538] CHIP:TOO: CharString attribute Response: TEST_VENDOR [1638338582.608517][189533:189538] CHIP:DMG: Client[0] moving to [UNINIT] [1638338582.608582][189533:189538] CHIP:EM: Sending Standalone Ack for MessageCounter:1 on exchange 19288i [1638338582.608704][189533:189538] CHIP:IN: Prepared encrypted message 0xffff84824980 to 0x0000000000BC5C01 (1) of type 0x10 and protocolId (0, 0) on exchange 19288i with MessageCounter:2. [1638338582.608794][189533:189538] CHIP:IN: Sending encrypted msg 0xffff84824980 with MessageCounter:2 to 0x0000000000BC5C01 (1) at monotonic time: 99521765 msec [1638338582.609032][189533:189538] CHIP:EM: Flushed pending ack for MessageCounter:1 on exchange 19288i [1638338582.609401][189533:189533] CHIP:CTL: Shutting down the commissioner [1638338582.609670][189533:189533] CHIP:CTL: Shutting down the controller [1638338582.611208][189533:189533] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1638338582.611734][189533:189533] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-LE04eg) [1638338582.612922][189533:189533] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1638338582.613040][189533:189533] CHIP:DL: NVS set: chip-counters/total-operational-hours = 2 (0x2) [1638338582.613105][189533:189533] CHIP:DL: Inet Layer shutdown [1638338582.613160][189533:189533] CHIP:DL: BLE shutdown [1638338582.613214][189533:189533] CHIP:DL: System Layer shutdown [1638338582.613424][189533:189533] CHIP:CSL: System wake event notify failed: ../../examples/chip-tool/third_party/connectedhomeip/src/system/WakeEvent.cpp:116: OS Error 0x02000009: Bad file descriptor [1638338582.613569][189533:189533] CHIP:CSL: System wake event notify failed: ../../examples/chip-tool/third_party/connectedhomeip/src/system/WakeEvent.cpp:116: OS Error 0x02000009: Bad file descriptor [1638338582.621591][189533:189533] CHIP:SPT: VerifyOrDie failure at ../../examples/chip-tool/third_party/connectedhomeip/src/inet/InetLayer.h:100: sEndPointPool.Allocated() == 0