Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

TE7.5 [TC-BOOL-1.1] VerifyOrDie failure at ../../examples/chip-tool/third_party/connectedhomeip/src/inet/InetLayer.h:121: sEndPointPool.Allocated() == 0 Aborted (core dumped) #14476

Closed
Minan-Tuyasmart opened this issue Jan 28, 2022 · 1 comment

Comments

@Minan-Tuyasmart
Copy link

platform:
Testing image on RasPi:v1.7.img
Connectedhomeip commitID : b0af6ba
OTBR commitID:72bb3d45684f837e67e7f1ec20a9a8e3ac4a4419
lighting-app run on the EFR32MG24 board base on commitID : b0af6ba

commissioning:

[1643339377.324928][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-J1qqZK)
[1643339377.325177][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1643339377.325439][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_config.ini-Ce7r5X)
[1643339377.325603][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1643339377.325826][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-IaKMfL)
[1643339377.325966][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1643339377.326198][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-HS6ODs)
[1643339377.326782][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1643339377.326841][3171:3171] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1)
[1643339377.326997][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ZzmrB8)
[1643339377.328251][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1643339377.328310][3171:3171] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1643339377.328472][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-BQf2X5)
[1643339377.329149][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1643339377.329204][3171:3171] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0)
[1643339377.329352][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_config.ini-NmlblH)
[1643339377.329756][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1643339377.329806][3171:3171] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0)
[1643339377.330033][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_config.ini-JHoxnv)
[1643339377.331040][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1643339377.331103][3171:3171] CHIP:DL: NVS set: chip-config/location-capability = 0 (0x0)
[1643339377.332004][3171:3171] CHIP:DL: Got Ethernet interface: eth0
[1643339377.332621][3171:3171] CHIP:DL: Found the primary Ethernet interface:eth0
[1643339377.333274][3171:3171] CHIP:DL: Got WiFi interface: wlan0
[1643339377.333355][3171:3171] CHIP:DL: Failed to reset WiFi statistic counts
[1643339377.333423][3171:3171] CHIP:IN: UDP::Init bind&listen port=5542
[1643339377.333742][3171:3171] CHIP:IN: UDP::Init bound to port=5542
[1643339377.333774][3171:3171] CHIP:IN: UDP::Init bind&listen port=5542
[1643339377.333866][3171:3171] CHIP:IN: UDP::Init bound to port=5542
[1643339377.333893][3171:3171] CHIP:IN: TransportMgr initialized
[1643339377.333934][3171:3171] CHIP:DIS: Init fabric pairing table with server storage
[1643339377.334211][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-LWnggd)
[1643339377.334833][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1643339377.334890][3171:3171] CHIP:DL: NVS set: chip-counters/GlobalMCTR = 1000 (0x3E8)
[1643339377.335013][3171:3171] CHIP:ZCL: Using ZAP configuration...
[1643339377.338321][3171:3171] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339377.345693][3171:3171] CHIP:DL: MDNS failed to join multicast group on veth8ac736a for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339377.347571][3171:3171] CHIP:DL: MDNS failed to join multicast group on veth54a3921 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339377.349380][3171:3171] CHIP:DL: MDNS failed to join multicast group on veth1c1f146 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339377.351416][3171:3171] CHIP:DL: MDNS failed to join multicast group on wpan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339377.351766][3171:3171] CHIP:CTL: System State Initialized...
[1643339377.358452][3171:3171] CHIP:CTL: Generating NOC
[1643339377.359061][3171:3171] CHIP:CTL: Generating ICAC
[1643339377.359425][3171:3171] CHIP:CTL: Generating RCAC
[1643339377.360853][3171:3171] CHIP:DIS: Verifying the received credentials
[1643339377.362872][3171:3171] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey
[1643339377.362924][3171:3171] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339377.362947][3171:3171] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339377.362967][3171:3171] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339377.362987][3171:3171] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339377.363007][3171:3171] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339377.363026][3171:3171] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339377.363044][3171:3171] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339377.363064][3171:3171] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339377.363080][3171:3171] CHIP:IN: 0xf4,
[1643339377.363141][3171:3171] CHIP:IN: Generated compressed fabric ID
[1643339377.363166][3171:3171] CHIP:IN: 0x8d, 0x53, 0xb2, 0x75, 0x5d, 0x55, 0x94, 0xb6,
[1643339377.363203][3171:3171] CHIP:DIS: Added new fabric at index: 1, Initialized: 1
[1643339377.363227][3171:3171] CHIP:DIS: Assigned compressed fabric ID: 0x8D53B2755D5594B6, node ID: 0x000000000001B669
[1643339377.363247][3171:3171] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x8D53B2755D5594B6
[1643339377.363356][3171:3171] CHIP:IN: UDP::Init bind&listen port=5550
[1643339377.363488][3171:3171] CHIP:IN: UDP::Init bound to port=5550
[1643339377.363514][3171:3171] CHIP:IN: UDP::Init bind&listen port=5550
[1643339377.363607][3171:3171] CHIP:IN: UDP::Init bound to port=5550
[1643339377.363635][3171:3171] CHIP:IN: TransportMgr initialized
[1643339377.365017][3171:3171] CHIP:CTL: Generating NOC
[1643339377.365386][3171:3171] CHIP:CTL: Generating ICAC
[1643339377.365675][3171:3171] CHIP:CTL: Generating RCAC
[1643339377.367685][3171:3171] CHIP:DIS: Verifying the received credentials
[1643339377.369744][3171:3171] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000002 and root pubkey
[1643339377.369792][3171:3171] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339377.369820][3171:3171] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339377.369847][3171:3171] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339377.369874][3171:3171] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339377.369900][3171:3171] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339377.369926][3171:3171] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339377.369951][3171:3171] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339377.369977][3171:3171] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339377.370012][3171:3171] CHIP:IN: 0xf4,
[1643339377.370073][3171:3171] CHIP:IN: Generated compressed fabric ID
[1643339377.370103][3171:3171] CHIP:IN: 0x4e, 0xa6, 0x96, 0x46, 0x5f, 0xfc, 0x9b, 0xa0,
[1643339377.370146][3171:3171] CHIP:DIS: Added new fabric at index: 2, Initialized: 1
[1643339377.370172][3171:3171] CHIP:DIS: Assigned compressed fabric ID: 0x4EA696465FFC9BA0, node ID: 0x000000000001B669
[1643339377.370198][3171:3171] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x4EA696465FFC9BA0
[1643339377.370293][3171:3171] CHIP:IN: UDP::Init bind&listen port=5550
[1643339377.370452][3171:3171] CHIP:IN: UDP::Init bound to port=5550
[1643339377.370501][3171:3171] CHIP:IN: UDP::Init bind&listen port=5550
[1643339377.370621][3171:3171] CHIP:IN: UDP::Init bound to port=5550
[1643339377.370650][3171:3171] CHIP:IN: TransportMgr initialized
[1643339377.372010][3171:3171] CHIP:CTL: Generating NOC
[1643339377.372380][3171:3171] CHIP:CTL: Generating ICAC
[1643339377.372669][3171:3171] CHIP:CTL: Generating RCAC
[1643339377.374222][3171:3171] CHIP:DIS: Verifying the received credentials
[1643339377.376385][3171:3171] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000003 and root pubkey
[1643339377.376430][3171:3171] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339377.376454][3171:3171] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339377.376478][3171:3171] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339377.376500][3171:3171] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339377.376523][3171:3171] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339377.376545][3171:3171] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339377.376567][3171:3171] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339377.376590][3171:3171] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339377.376610][3171:3171] CHIP:IN: 0xf4,
[1643339377.376679][3171:3171] CHIP:IN: Generated compressed fabric ID
[1643339377.376707][3171:3171] CHIP:IN: 0x6a, 0xd6, 0x18, 0xf2, 0xf7, 0x73, 0xdf, 0x14,
[1643339377.376735][3171:3171] CHIP:DIS: Added new fabric at index: 3, Initialized: 1
[1643339377.376768][3171:3171] CHIP:DIS: Assigned compressed fabric ID: 0x6AD618F2F773DF14, node ID: 0x000000000001B669
[1643339377.376791][3171:3171] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x6AD618F2F773DF14
[1643339377.376885][3171:3171] CHIP:IN: UDP::Init bind&listen port=5550
[1643339377.377026][3171:3171] CHIP:IN: UDP::Init bound to port=5550
[1643339377.377053][3171:3171] CHIP:IN: UDP::Init bind&listen port=5550
[1643339377.377144][3171:3171] CHIP:IN: UDP::Init bound to port=5550
[1643339377.377168][3171:3171] CHIP:IN: TransportMgr initialized
[1643339377.377476][3171:3176] CHIP:DL: CHIP task running
[1643339377.377869][3171:3176] CHIP:SC: Assigned local session key ID 1
[1643339377.378017][3171:3176] CHIP:SC: Including MRP parameters in PBKDF param request
[1643339377.378074][3171:3176] CHIP:IN: Prepared plaintext message 0xffffabffdd98 to 0x0000000000000000 (0)  of type 0x20 and protocolId (0, 0) on exchange 54697i with MessageCounter:4121202567.
[1643339377.378118][3171:3176] CHIP:IN: Sending plaintext msg 0xffffabffdd98 with MessageCounter:4121202567 to 0x0000000000000000 at monotonic time: 343147 msec
[1643339377.378158][3171:3176] CHIP:IN: Message appended to BLE send queue
[1643339377.378182][3171:3176] CHIP:SC: Sent PBKDF param request
[1643339377.379349][3171:3177] CHIP:DL: TRACE: Bluez mainloop starting Thread
[1643339377.379689][3171:3174] CHIP:DL: TRACE: Bus acquired for name C-0c63
[1643339377.386798][3171:3176] CHIP:DL: PlatformBlueZInit init success
[1643339377.393201][3171:3174] CHIP:BLE: BLE removing known devices.
[1643339377.395152][3171:3174] CHIP:BLE: BLE initiating scan.
[1643339377.403988][3171:3174] CHIP:BLE: Device 6A:72:0F:08:65:02 does not look like a CHIP device.
[1643339377.420029][3171:3174] CHIP:BLE: Device 3D:8D:BC:D0:A7:09 does not look like a CHIP device.
[1643339377.440858][3171:3174] CHIP:BLE: Device 4B:91:5E:D4:86:29 does not look like a CHIP device.
[1643339377.444518][3171:3174] CHIP:BLE: Device D8:1F:12:4B:0B:7C does not look like a CHIP device.
[1643339377.448531][3171:3174] CHIP:BLE: Device 33:2A:C4:9B:B8:F1 does not look like a CHIP device.
[1643339377.453791][3171:3174] CHIP:BLE: New device scanned: 84:71:27:6F:F0:38
[1643339377.453844][3171:3174] CHIP:BLE: Device discriminator match. Attempting to connect.
[1643339377.456980][3171:3174] CHIP:BLE: Scan complete notification without an active scan.
[1643339377.654524][3171:3174] CHIP:DL: ConnectDevice complete
[1643339378.207902][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.208035][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208066][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.208091][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208119][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.208142][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208173][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208196][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208229][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.208252][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208277][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.208299][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208351][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.208376][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208407][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service000e
[1643339378.208430][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208455][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service000e
[1643339378.208477][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208515][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service000e
[1643339378.208538][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208571][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service000e
[1643339378.208593][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208618][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service000e
[1643339378.208641][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208678][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service000e
[1643339378.208700][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208729][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service001b
[1643339378.208752][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208790][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service001b
[1643339378.208813][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208839][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service001b
[1643339378.208861][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208904][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.208927][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.208953][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.208975][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.209012][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0001
[1643339378.209035][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.209064][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.209087][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.209127][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.209150][3171:3174] CHIP:DL: Char1 /org/bluez/hci0/dev_84_71_27_6F_F0_38/service0015
[1643339378.209182][3171:3174] CHIP:DL: New BLE connection 0xffffb0045220, device 84:71:27:6F:F0:38, path /org/bluez/hci0/dev_84_71_27_6F_F0_38
[1643339378.209387][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16385
[1643339378.209426][3171:3176] CHIP:IN: BleConnectionComplete: endPoint 0xaaaab36ab448
[1643339378.724938][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339378.823103][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1643339378.823199][3171:3176] CHIP:BLE: subscribe complete, ep = 0xaaaab36ab448
[1643339378.823513][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339378.823826][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339378.823900][3171:3176] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4
[1643339378.823953][3171:3176] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244.
[1643339378.824003][3171:3176] CHIP:BLE: local and remote recv window size = 5
[1643339378.824211][3171:3176] CHIP:IN: BLE EndPoint 0xaaaab36ab448 Connection Complete
[1643339378.919926][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339380.140493][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339380.140891][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339380.141074][3171:3176] CHIP:EM: Received message of type 0x21 with protocolId (0, 0) and MessageCounter:4151490776 on exchange 54697i
[1643339380.141151][3171:3176] CHIP:EM: Found matching exchange: 54697i, Delegate: 0xffffb84f1af0
[1643339380.141238][3171:3176] CHIP:SC: Received PBKDF param response
[1643339380.141326][3171:3176] CHIP:SC: Peer assigned session ID 1
[1643339380.141400][3171:3176] CHIP:SC: Found MRP parameters in the message
[1643339380.144576][3171:3176] CHIP:IN: Prepared plaintext message 0xffffabffd8d8 to 0x0000000000000000 (0)  of type 0x22 and protocolId (0, 0) on exchange 54697i with MessageCounter:4121202568.
[1643339380.144681][3171:3176] CHIP:IN: Sending plaintext msg 0xffffabffd8d8 with MessageCounter:4121202568 to 0x0000000000000000 at monotonic time: 345914 msec
[1643339380.144876][3171:3176] CHIP:SC: Sent spake2p msg1
[1643339380.235964][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339384.089319][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.089720][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.089917][3171:3176] CHIP:EM: Received message of type 0x23 with protocolId (0, 0) and MessageCounter:4151490777 on exchange 54697i
[1643339384.089991][3171:3176] CHIP:EM: Found matching exchange: 54697i, Delegate: 0xffffb84f1af0
[1643339384.090080][3171:3176] CHIP:SC: Received spake2p msg2
[1643339384.093158][3171:3176] CHIP:IN: Prepared plaintext message 0xffffabffd9c8 to 0x0000000000000000 (0)  of type 0x24 and protocolId (0, 0) on exchange 54697i with MessageCounter:4121202569.
[1643339384.093379][3171:3176] CHIP:IN: Sending plaintext msg 0xffffabffd9c8 with MessageCounter:4121202569 to 0x0000000000000000 at monotonic time: 349862 msec
[1643339384.093576][3171:3176] CHIP:SC: Sent spake2p msg3
[1643339384.233714][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339384.234367][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.234715][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.234992][3171:3176] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:4151490778 on exchange 54697i
[1643339384.235067][3171:3176] CHIP:EM: Found matching exchange: 54697i, Delegate: 0xffffb84f1af0
[1643339384.235168][3171:3176] CHIP:IN: New secure session created for device 0x0000000000BC5C01, key 1!!
[1643339384.235413][3171:3176] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1643339384.235501][3171:3176] CHIP:CTL: Arming failsafe
[1643339384.235723][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339384.235819][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339384.235982][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffd4c8 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54698i with MessageCounter:8036351.
[1643339384.236097][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffd4c8 with MessageCounter:8036351 to 0x0000000000BC5C01 (1) at monotonic time: 350005 msec
[1643339384.236312][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339384.330726][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339384.332135][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.332404][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.332612][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294147 on exchange 54698i
[1643339384.332663][3171:3176] CHIP:EM: Found matching exchange: 54698i, Delegate: 0xffffa40058b0
[1643339384.332736][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339384.332804][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339384.332845][3171:3176] CHIP:DMG: {
[1643339384.332884][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339384.332924][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339384.332975][3171:3176] CHIP:DMG:        [
[1643339384.333032][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339384.333095][3171:3176] CHIP:DMG:                {
[1643339384.333138][3171:3176] CHIP:DMG:                        CommandStatusIB =
[1643339384.333203][3171:3176] CHIP:DMG:                        {
[1643339384.333258][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339384.333317][3171:3176] CHIP:DMG:                                {
[1643339384.333388][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339384.333452][3171:3176] CHIP:DMG:                                        ClusterId = 0x30,
[1643339384.333510][3171:3176] CHIP:DMG:                                        CommandId = 0x0,
[1643339384.333577][3171:3176] CHIP:DMG:                                },
[1643339384.333638][3171:3176] CHIP:DMG:
[1643339384.333700][3171:3176] CHIP:DMG:                                StatusIB =
[1643339384.333755][3171:3176] CHIP:DMG:                                {
[1643339384.333808][3171:3176] CHIP:DMG:                                        status = 0x0,
[1643339384.333873][3171:3176] CHIP:DMG:                                },
[1643339384.333933][3171:3176] CHIP:DMG:
[1643339384.333982][3171:3176] CHIP:DMG:                        },
[1643339384.334051][3171:3176] CHIP:DMG:
[1643339384.334095][3171:3176] CHIP:DMG:                },
[1643339384.334162][3171:3176] CHIP:DMG:
[1643339384.334202][3171:3176] CHIP:DMG:        ],
[1643339384.334249][3171:3176] CHIP:DMG:
[1643339384.334285][3171:3176] CHIP:DMG: },
[1643339384.334391][3171:3176] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 Status=0x0
[1643339384.334435][3171:3176] CHIP:ZCL: DefaultResponse:
[1643339384.334519][3171:3176] CHIP:ZCL:   Transaction: 0xffffa40058b0
[1643339384.334554][3171:3176] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1643339384.334593][3171:3176] CHIP:CTL: Received success response 0x1834

[1643339384.334663][3171:3176] CHIP:CTL: Setting Regulatory Config
[1643339384.334789][3171:3176] CHIP:CTL: Unable to find country code, defaulting to WW
[1643339384.334915][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339384.334967][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339384.335085][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffd058 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54699i with MessageCounter:8036352.
[1643339384.335165][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffd058 with MessageCounter:8036352 to 0x0000000000BC5C01 (1) at monotonic time: 350104 msec
[1643339384.335322][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339384.335392][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339384.526314][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339384.527502][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.527997][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.528203][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294148 on exchange 54699i
[1643339384.528264][3171:3176] CHIP:EM: Found matching exchange: 54699i, Delegate: 0xffffa4004a00
[1643339384.528350][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339384.528426][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339384.528474][3171:3176] CHIP:DMG: {
[1643339384.528519][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339384.528564][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339384.528620][3171:3176] CHIP:DMG:        [
[1643339384.528686][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339384.528756][3171:3176] CHIP:DMG:                {
[1643339384.528809][3171:3176] CHIP:DMG:                        CommandStatusIB =
[1643339384.528898][3171:3176] CHIP:DMG:                        {
[1643339384.528962][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339384.529039][3171:3176] CHIP:DMG:                                {
[1643339384.529111][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339384.529199][3171:3176] CHIP:DMG:                                        ClusterId = 0x30,
[1643339384.529274][3171:3176] CHIP:DMG:                                        CommandId = 0x2,
[1643339384.529341][3171:3176] CHIP:DMG:                                },
[1643339384.529431][3171:3176] CHIP:DMG:
[1643339384.529494][3171:3176] CHIP:DMG:                                StatusIB =
[1643339384.529579][3171:3176] CHIP:DMG:                                {
[1643339384.529647][3171:3176] CHIP:DMG:                                        status = 0x0,
[1643339384.529732][3171:3176] CHIP:DMG:                                },
[1643339384.529801][3171:3176] CHIP:DMG:
[1643339384.529875][3171:3176] CHIP:DMG:                        },
[1643339384.529947][3171:3176] CHIP:DMG:
[1643339384.529999][3171:3176] CHIP:DMG:                },
[1643339384.530077][3171:3176] CHIP:DMG:
[1643339384.530120][3171:3176] CHIP:DMG:        ],
[1643339384.530189][3171:3176] CHIP:DMG:
[1643339384.530232][3171:3176] CHIP:DMG: },
[1643339384.530349][3171:3176] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 Status=0x0
[1643339384.530400][3171:3176] CHIP:ZCL: DefaultResponse:
[1643339384.530436][3171:3176] CHIP:ZCL:   Transaction: 0xffffa4004a00
[1643339384.530502][3171:3176] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1643339384.530549][3171:3176] CHIP:CTL: Received success response 0x1834

[1643339384.530627][3171:3176] CHIP:CTL: Exchanging vendor certificates
[1643339384.530664][3171:3176] CHIP:CTL: Sending Certificate Chain request to 0xffffb84f1a98 device
[1643339384.530738][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339384.530805][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339384.530938][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffcf98 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54700i with MessageCounter:8036353.
[1643339384.531032][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffcf98 with MessageCounter:8036353 to 0x0000000000BC5C01 (1) at monotonic time: 350300 msec
[1643339384.531208][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339384.531282][3171:3176] CHIP:CTL: Sent Certificate Chain request, waiting for the DAC Certificate
[1643339384.531340][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339384.623720][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339384.627054][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.627470][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.629542][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.630008][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.630569][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.630669][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.630878][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294149 on exchange 54700i
[1643339384.630952][3171:3176] CHIP:EM: Found matching exchange: 54700i, Delegate: 0xffffa40058b0
[1643339384.631048][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339384.631148][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339384.631210][3171:3176] CHIP:DMG: {
[1643339384.631269][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339384.631328][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339384.631405][3171:3176] CHIP:DMG:        [
[1643339384.631464][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339384.631556][3171:3176] CHIP:DMG:                {
[1643339384.631625][3171:3176] CHIP:DMG:                        CommandDataIB =
[1643339384.631709][3171:3176] CHIP:DMG:                        {
[1643339384.631791][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339384.631879][3171:3176] CHIP:DMG:                                {
[1643339384.631969][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339384.632183][3171:3176] CHIP:DMG:                                        ClusterId = 0x3e,
[1643339384.632278][3171:3176] CHIP:DMG:                                        CommandId = 0x3,
[1643339384.632365][3171:3176] CHIP:DMG:                                },
[1643339384.632451][3171:3176] CHIP:DMG:
[1643339384.632532][3171:3176] CHIP:DMG:                                CommandData =
[1643339384.632613][3171:3176] CHIP:DMG:                                {
[1643339384.632694][3171:3176] CHIP:DMG:                                        0x0 = [
[1643339384.632782][3171:3176] CHIP:DMG:                                                ... (byte string too long) ...
[1643339384.632877][3171:3176] CHIP:DMG:                                ]
[1643339384.632957][3171:3176] CHIP:DMG:                                },
[1643339384.633039][3171:3176] CHIP:DMG:                        },
[1643339384.633125][3171:3176] CHIP:DMG:
[1643339384.633193][3171:3176] CHIP:DMG:                },
[1643339384.633273][3171:3176] CHIP:DMG:
[1643339384.633331][3171:3176] CHIP:DMG:        ],
[1643339384.633402][3171:3176] CHIP:DMG:
[1643339384.633456][3171:3176] CHIP:DMG: },
[1643339384.633553][3171:3176] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1643339384.633657][3171:3176] CHIP:ZCL: CertificateChainResponse:
[1643339384.633691][3171:3176] CHIP:ZCL:   Certificate: 472
[1643339384.633724][3171:3176] CHIP:CTL: Received certificate chain from the device
[1643339384.633755][3171:3176] CHIP:CTL: Sending Certificate Chain request to 0xffffb84f1a98 device
[1643339384.633814][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339384.633849][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339384.633950][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffd088 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54701i with MessageCounter:8036354.
[1643339384.634003][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffd088 with MessageCounter:8036354 to 0x0000000000BC5C01 (1) at monotonic time: 350403 msec
[1643339384.634128][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339384.634165][3171:3176] CHIP:CTL: Sent Certificate Chain request, waiting for the DAC Certificate
[1643339384.634214][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339384.769925][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339384.773372][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.773739][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.775737][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.776214][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339384.776608][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.776717][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339384.776932][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294150 on exchange 54701i
[1643339384.777031][3171:3176] CHIP:EM: Found matching exchange: 54701i, Delegate: 0xffffa4004a00
[1643339384.777125][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339384.777225][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339384.777285][3171:3176] CHIP:DMG: {
[1643339384.777344][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339384.777428][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339384.777505][3171:3176] CHIP:DMG:        [
[1643339384.777564][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339384.777678][3171:3176] CHIP:DMG:                {
[1643339384.777718][3171:3176] CHIP:DMG:                        CommandDataIB =
[1643339384.777764][3171:3176] CHIP:DMG:                        {
[1643339384.777825][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339384.777878][3171:3176] CHIP:DMG:                                {
[1643339384.777941][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339384.777999][3171:3176] CHIP:DMG:                                        ClusterId = 0x3e,
[1643339384.778051][3171:3176] CHIP:DMG:                                        CommandId = 0x3,
[1643339384.778116][3171:3176] CHIP:DMG:                                },
[1643339384.778173][3171:3176] CHIP:DMG:
[1643339384.778228][3171:3176] CHIP:DMG:                                CommandData =
[1643339384.778277][3171:3176] CHIP:DMG:                                {
[1643339384.778331][3171:3176] CHIP:DMG:                                        0x0 = [
[1643339384.778396][3171:3176] CHIP:DMG:                                                ... (byte string too long) ...
[1643339384.778448][3171:3176] CHIP:DMG:                                ]
[1643339384.778562][3171:3176] CHIP:DMG:                                },
[1643339384.778615][3171:3176] CHIP:DMG:                        },
[1643339384.778680][3171:3176] CHIP:DMG:
[1643339384.778721][3171:3176] CHIP:DMG:                },
[1643339384.778769][3171:3176] CHIP:DMG:
[1643339384.778821][3171:3176] CHIP:DMG:        ],
[1643339384.778866][3171:3176] CHIP:DMG:
[1643339384.778898][3171:3176] CHIP:DMG: },
[1643339384.778987][3171:3176] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1643339384.779052][3171:3176] CHIP:ZCL: CertificateChainResponse:
[1643339384.779085][3171:3176] CHIP:ZCL:   Certificate: 494
[1643339384.779120][3171:3176] CHIP:CTL: Received certificate chain from the device
[1643339384.779157][3171:3176] CHIP:CTL: Sending Attestation Request to the device.
[1643339384.779200][3171:3176] CHIP:CTL: Sending Attestation request to 0xffffb84f1a98 device
[1643339384.779264][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339384.779306][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339384.779436][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffd078 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54702i with MessageCounter:8036355.
[1643339384.779494][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffd078 with MessageCounter:8036355 to 0x0000000000BC5C01 (1) at monotonic time: 350549 msec
[1643339384.779660][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339384.779703][3171:3176] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information
[1643339384.779753][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339384.867034][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339385.650782][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339385.651453][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339385.652039][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339385.652306][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339385.652480][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294151 on exchange 54702i
[1643339385.652539][3171:3176] CHIP:EM: Found matching exchange: 54702i, Delegate: 0xffffa40058b0
[1643339385.652610][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339385.652688][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339385.652736][3171:3176] CHIP:DMG: {
[1643339385.652780][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339385.652827][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339385.652886][3171:3176] CHIP:DMG:        [
[1643339385.652931][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339385.652997][3171:3176] CHIP:DMG:                {
[1643339385.653045][3171:3176] CHIP:DMG:                        CommandDataIB =
[1643339385.653101][3171:3176] CHIP:DMG:                        {
[1643339385.653154][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339385.653220][3171:3176] CHIP:DMG:                                {
[1643339385.653288][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339385.653353][3171:3176] CHIP:DMG:                                        ClusterId = 0x3e,
[1643339385.653417][3171:3176] CHIP:DMG:                                        CommandId = 0x1,
[1643339385.653476][3171:3176] CHIP:DMG:                                },
[1643339385.653541][3171:3176] CHIP:DMG:
[1643339385.653596][3171:3176] CHIP:DMG:                                CommandData =
[1643339385.653655][3171:3176] CHIP:DMG:                                {
[1643339385.653720][3171:3176] CHIP:DMG:                                        0x0 = [
[1643339385.653780][3171:3176] CHIP:DMG:                                                ... (byte string too long) ...
[1643339385.653847][3171:3176] CHIP:DMG:                                ]
[1643339385.653914][3171:3176] CHIP:DMG:                                        0x1 = [
[1643339385.654001][3171:3176] CHIP:DMG:                                                0x73, 0xe6, 0xc8, 0xc5, 0x8e, 0x47, 0x77, 0xbb, 0xaa, 0x35, 0x43, 0x33, 0x7a, 0xba, 0xf9, 0xac, 0x15, 0xe4, 0x7e, 0x32, 0x70, 0xcb, 0x5a, 0x49, 0x70, 0x7f, 0xa9, 0xa, 0xc4, 0x5f, 0xfa, 0xb6, 0xf7, 0xcd, 0x59, 0x3c, 0xbc, 0x54, 0x12, 0xa5, 0xb4, 0x93
[1643339385.654071][3171:3176] CHIP:DMG:                                ]
[1643339385.654136][3171:3176] CHIP:DMG:                                },
[1643339385.654198][3171:3176] CHIP:DMG:                        },
[1643339385.654262][3171:3176] CHIP:DMG:
[1643339385.654312][3171:3176] CHIP:DMG:                },
[1643339385.654374][3171:3176] CHIP:DMG:
[1643339385.654418][3171:3176] CHIP:DMG:        ],
[1643339385.654510][3171:3176] CHIP:DMG:
[1643339385.654556][3171:3176] CHIP:DMG: },
[1643339385.654666][3171:3176] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1643339385.654730][3171:3176] CHIP:ZCL: AttestationResponse:
[1643339385.654769][3171:3176] CHIP:ZCL:   AttestationElements: 278
[1643339385.654805][3171:3176] CHIP:ZCL:   Signature: 64
[1643339385.654847][3171:3176] CHIP:CTL: Received Attestation Information from the device
[1643339385.664359][3171:3176] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device.
[1643339385.664410][3171:3176] CHIP:CTL: Sending 'CSR request' command to the device.
[1643339385.664430][3171:3176] CHIP:CTL: Sending OpCSR request to 0xffffb84f1a98 device
[1643339385.664530][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339385.664561][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339385.664662][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffd048 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54703i with MessageCounter:8036356.
[1643339385.664719][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffd048 with MessageCounter:8036356 to 0x0000000000BC5C01 (1) at monotonic time: 351434 msec
[1643339385.664847][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339385.664880][3171:3176] CHIP:CTL: Sent OpCSR request, waiting for the CSR
[1643339385.664923][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339385.744872][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339388.868051][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339388.868446][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339388.869821][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339388.870188][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339388.870407][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294152 on exchange 54703i
[1643339388.870514][3171:3176] CHIP:EM: Found matching exchange: 54703i, Delegate: 0xffffa4004a00
[1643339388.870611][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339388.870711][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339388.870772][3171:3176] CHIP:DMG: {
[1643339388.870829][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339388.870891][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339388.870968][3171:3176] CHIP:DMG:        [
[1643339388.871026][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339388.871112][3171:3176] CHIP:DMG:                {
[1643339388.871176][3171:3176] CHIP:DMG:                        CommandDataIB =
[1643339388.871251][3171:3176] CHIP:DMG:                        {
[1643339388.871332][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339388.871419][3171:3176] CHIP:DMG:                                {
[1643339388.871509][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339388.871597][3171:3176] CHIP:DMG:                                        ClusterId = 0x3e,
[1643339388.871687][3171:3176] CHIP:DMG:                                        CommandId = 0x5,
[1643339388.871768][3171:3176] CHIP:DMG:                                },
[1643339388.871860][3171:3176] CHIP:DMG:
[1643339388.871934][3171:3176] CHIP:DMG:                                CommandData =
[1643339388.872014][3171:3176] CHIP:DMG:                                {
[1643339388.872102][3171:3176] CHIP:DMG:                                        0x0 = [
[1643339388.872240][3171:3176] CHIP:DMG:                                                0x15, 0x30, 0x1, 0xcd, 0x30, 0x81, 0xca, 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
[1643339388.872343][3171:3176] CHIP:DMG:                                ]
[1643339388.872430][3171:3176] CHIP:DMG:                                        0x1 = [
[1643339388.872552][3171:3176] CHIP:DMG:                                                0x86, 0xf1, 0xb3, 0x44, 0xa2, 0xeb, 0x28, 0x29, 0xcf, 0xc7, 0x71, 0xf8, 0x5, 0xab, 0x7b, 0x4d, 0xeb, 0xc6, 0x30, 0x88, 0x68, 0xf6, 0x18, 0x3b, 0xc0, 0xf0, 0x6f, 0xd, 0xf0, 0x39, 0xca, 0x5b, 0x45, 0x72, 0x67, 0xe4, 0x92, 0xac, 0x5d, 0xe2, 0xec, 0x35,
[1643339388.872651][3171:3176] CHIP:DMG:                                ]
[1643339388.872739][3171:3176] CHIP:DMG:                                },
[1643339388.872814][3171:3176] CHIP:DMG:                        },
[1643339388.872900][3171:3176] CHIP:DMG:
[1643339388.872961][3171:3176] CHIP:DMG:                },
[1643339388.873036][3171:3176] CHIP:DMG:
[1643339388.873094][3171:3176] CHIP:DMG:        ],
[1643339388.873166][3171:3176] CHIP:DMG:
[1643339388.873220][3171:3176] CHIP:DMG: },
[1643339388.873368][3171:3176] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1643339388.873447][3171:3176] CHIP:ZCL: OpCSRResponse:
[1643339388.873498][3171:3176] CHIP:ZCL:   NOCSRElements: 245
[1643339388.873546][3171:3176] CHIP:ZCL:   AttestationSignature: 64
[1643339388.873601][3171:3176] CHIP:CTL: Received certificate signing request from the device
[1643339388.873652][3171:3176] CHIP:CTL: Getting certificate chain for the device from the issuer
[1643339388.876180][3171:3176] CHIP:CTL: Verifying Certificate Signing Request
[1643339388.877744][3171:3176] CHIP:CTL: Generating NOC
[1643339388.878162][3171:3176] CHIP:CTL: Generating ICAC
[1643339388.878533][3171:3176] CHIP:CTL: Providing certificate chain to the commissioner
[1643339388.878570][3171:3176] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../examples/chip-tool/third_party/connectedhomeip/src/controller/ExampleOperationalCredentialsIssuer.cpp:183: Success
[1643339388.878707][3171:3176] CHIP:CTL: Sending root certificate to the device
[1643339388.878771][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339388.878805][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339388.878923][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffccf8 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54704i with MessageCounter:8036357.
[1643339388.878973][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffccf8 with MessageCounter:8036357 to 0x0000000000BC5C01 (1) at monotonic time: 354648 msec
[1643339388.879099][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339388.879135][3171:3176] CHIP:CTL: Sent root certificate to the device
[1643339388.879314][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339389.011402][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339389.108846][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339389.158232][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339389.158600][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339389.158826][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294153 on exchange 54704i
[1643339389.158895][3171:3176] CHIP:EM: Found matching exchange: 54704i, Delegate: 0xffffa40058b0
[1643339389.158968][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339389.159054][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339389.159109][3171:3176] CHIP:DMG: {
[1643339389.159161][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339389.159212][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339389.159278][3171:3176] CHIP:DMG:        [
[1643339389.159330][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339389.159408][3171:3176] CHIP:DMG:                {
[1643339389.159463][3171:3176] CHIP:DMG:                        CommandStatusIB =
[1643339389.159523][3171:3176] CHIP:DMG:                        {
[1643339389.159576][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339389.159651][3171:3176] CHIP:DMG:                                {
[1643339389.159715][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339389.159795][3171:3176] CHIP:DMG:                                        ClusterId = 0x3e,
[1643339389.159866][3171:3176] CHIP:DMG:                                        CommandId = 0xb,
[1643339389.159940][3171:3176] CHIP:DMG:                                },
[1643339389.160022][3171:3176] CHIP:DMG:
[1643339389.160087][3171:3176] CHIP:DMG:                                StatusIB =
[1643339389.160156][3171:3176] CHIP:DMG:                                {
[1643339389.160224][3171:3176] CHIP:DMG:                                        status = 0x0,
[1643339389.160300][3171:3176] CHIP:DMG:                                },
[1643339389.160375][3171:3176] CHIP:DMG:
[1643339389.160437][3171:3176] CHIP:DMG:                        },
[1643339389.160508][3171:3176] CHIP:DMG:
[1643339389.160561][3171:3176] CHIP:DMG:                },
[1643339389.160624][3171:3176] CHIP:DMG:
[1643339389.160673][3171:3176] CHIP:DMG:        ],
[1643339389.160734][3171:3176] CHIP:DMG:
[1643339389.160779][3171:3176] CHIP:DMG: },
[1643339389.160894][3171:3176] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1643339389.160949][3171:3176] CHIP:ZCL: DefaultResponse:
[1643339389.160990][3171:3176] CHIP:ZCL:   Transaction: 0xffffa40058b0
[1643339389.161032][3171:3176] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1643339389.161081][3171:3176] CHIP:CTL: Device confirmed that it has received the root certificate
[1643339389.161125][3171:3176] CHIP:CTL: Sending operational certificate chain to the device
[1643339389.161207][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339389.161268][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339389.161460][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffd238 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54705i with MessageCounter:8036358.
[1643339389.161541][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffd238 with MessageCounter:8036358 to 0x0000000000BC5C01 (1) at monotonic time: 354931 msec
[1643339389.161707][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339389.161764][3171:3176] CHIP:CTL: Sent operational certificate to the device
[1643339389.161832][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339389.254947][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339389.351716][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339389.498137][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339389.548422][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339389.548791][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339389.549042][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294154 on exchange 54705i
[1643339389.549121][3171:3176] CHIP:EM: Found matching exchange: 54705i, Delegate: 0xffffa4004a00
[1643339389.549205][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339389.549304][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339389.549364][3171:3176] CHIP:DMG: {
[1643339389.549425][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339389.549485][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339389.549562][3171:3176] CHIP:DMG:        [
[1643339389.549621][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339389.549715][3171:3176] CHIP:DMG:                {
[1643339389.549779][3171:3176] CHIP:DMG:                        CommandDataIB =
[1643339389.549853][3171:3176] CHIP:DMG:                        {
[1643339389.549932][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339389.550020][3171:3176] CHIP:DMG:                                {
[1643339389.550109][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339389.550202][3171:3176] CHIP:DMG:                                        ClusterId = 0x3e,
[1643339389.550286][3171:3176] CHIP:DMG:                                        CommandId = 0x8,
[1643339389.550372][3171:3176] CHIP:DMG:                                },
[1643339389.550457][3171:3176] CHIP:DMG:
[1643339389.550580][3171:3176] CHIP:DMG:                                CommandData =
[1643339389.550661][3171:3176] CHIP:DMG:                                {
[1643339389.550745][3171:3176] CHIP:DMG:                                        0x0 = 0,
[1643339389.550831][3171:3176] CHIP:DMG:                                        0x1 = 1,
[1643339389.550927][3171:3176] CHIP:DMG:                                        0x2 = "",
[1643339389.551011][3171:3176] CHIP:DMG:                                },
[1643339389.551087][3171:3176] CHIP:DMG:                        },
[1643339389.551171][3171:3176] CHIP:DMG:
[1643339389.551238][3171:3176] CHIP:DMG:                },
[1643339389.551319][3171:3176] CHIP:DMG:
[1643339389.551376][3171:3176] CHIP:DMG:        ],
[1643339389.551449][3171:3176] CHIP:DMG:
[1643339389.551502][3171:3176] CHIP:DMG: },
[1643339389.551647][3171:3176] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1643339389.551729][3171:3176] CHIP:ZCL: NOCResponse:
[1643339389.551782][3171:3176] CHIP:ZCL:   StatusCode: 0
[1643339389.551829][3171:3176] CHIP:ZCL:   FabricIndex: 1
[1643339389.551877][3171:3176] CHIP:ZCL:   DebugText:
[1643339389.551932][3171:3176] CHIP:CTL: Device returned status 0 on receiving the NOC
[1643339389.551985][3171:3176] CHIP:CTL: Operational credentials provisioned on device 0xffffb84f1a98
[1643339389.552062][3171:3176] CHIP:TOO: Secure Pairing Success
[1643339389.552115][3171:3176] CHIP:CTL: Adding thread network
[1643339389.552206][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339389.552273][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339389.552438][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffce38 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54706i with MessageCounter:8036359.
[1643339389.552532][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffce38 with MessageCounter:8036359 to 0x0000000000BC5C01 (1) at monotonic time: 355322 msec
[1643339389.552722][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339389.552819][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339389.645149][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339389.646636][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339389.647001][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339389.647249][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294155 on exchange 54706i
[1643339389.647325][3171:3176] CHIP:EM: Found matching exchange: 54706i, Delegate: 0xffffa40058b0
[1643339389.647410][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339389.647509][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339389.647571][3171:3176] CHIP:DMG: {
[1643339389.647630][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339389.647690][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339389.647767][3171:3176] CHIP:DMG:        [
[1643339389.647826][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339389.647918][3171:3176] CHIP:DMG:                {
[1643339389.647982][3171:3176] CHIP:DMG:                        CommandDataIB =
[1643339389.648057][3171:3176] CHIP:DMG:                        {
[1643339389.648137][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339389.648218][3171:3176] CHIP:DMG:                                {
[1643339389.648301][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339389.648386][3171:3176] CHIP:DMG:                                        ClusterId = 0x31,
[1643339389.648471][3171:3176] CHIP:DMG:                                        CommandId = 0x5,
[1643339389.648557][3171:3176] CHIP:DMG:                                },
[1643339389.648641][3171:3176] CHIP:DMG:
[1643339389.648715][3171:3176] CHIP:DMG:                                CommandData =
[1643339389.648795][3171:3176] CHIP:DMG:                                {
[1643339389.648885][3171:3176] CHIP:DMG:                                        0x0 = 0,
[1643339389.648981][3171:3176] CHIP:DMG:                                        0x1 = "",
[1643339389.649066][3171:3176] CHIP:DMG:                                },
[1643339389.649148][3171:3176] CHIP:DMG:                        },
[1643339389.649230][3171:3176] CHIP:DMG:
[1643339389.649295][3171:3176] CHIP:DMG:                },
[1643339389.649375][3171:3176] CHIP:DMG:
[1643339389.649432][3171:3176] CHIP:DMG:        ],
[1643339389.649503][3171:3176] CHIP:DMG:
[1643339389.649557][3171:3176] CHIP:DMG: },
[1643339389.649697][3171:3176] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1643339389.649776][3171:3176] CHIP:ZCL: NetworkConfigResponse:
[1643339389.649833][3171:3176] CHIP:ZCL:   NetworkingStatus: 0
[1643339389.649883][3171:3176] CHIP:ZCL:   DebugText:
[1643339389.649940][3171:3176] CHIP:CTL: Received success response 0x0

[1643339389.650027][3171:3176] CHIP:CTL: Enabling thread network
[1643339389.650120][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339389.650187][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339389.650340][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffced8 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54707i with MessageCounter:8036360.
[1643339389.650431][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffced8 with MessageCounter:8036360 to 0x0000000000BC5C01 (1) at monotonic time: 355419 msec
[1643339389.650661][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339389.650758][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339389.742398][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339389.744101][3171:3174] CHIP:DL: Indication received, conn = 0xffffb0045220
[1643339389.744454][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1643339389.744705][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8294156 on exchange 54707i
[1643339389.744782][3171:3176] CHIP:EM: Found matching exchange: 54707i, Delegate: 0xffffa4004a00
[1643339389.744866][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339389.744967][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339389.745027][3171:3176] CHIP:DMG: {
[1643339389.745086][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339389.745146][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339389.745226][3171:3176] CHIP:DMG:        [
[1643339389.745285][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339389.745374][3171:3176] CHIP:DMG:                {
[1643339389.745437][3171:3176] CHIP:DMG:                        CommandDataIB =
[1643339389.745513][3171:3176] CHIP:DMG:                        {
[1643339389.745594][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339389.745680][3171:3176] CHIP:DMG:                                {
[1643339389.745764][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339389.745850][3171:3176] CHIP:DMG:                                        ClusterId = 0x31,
[1643339389.745932][3171:3176] CHIP:DMG:                                        CommandId = 0x7,
[1643339389.746018][3171:3176] CHIP:DMG:                                },
[1643339389.746102][3171:3176] CHIP:DMG:
[1643339389.746167][3171:3176] CHIP:DMG:                                CommandData =
[1643339389.746253][3171:3176] CHIP:DMG:                                {
[1643339389.746344][3171:3176] CHIP:DMG:                                        0x0 = 0,
[1643339389.746441][3171:3176] CHIP:DMG:                                        0x1 = "",
[1643339389.746579][3171:3176] CHIP:DMG:                                        0x2 = 536946472,
[1643339389.746663][3171:3176] CHIP:DMG:                                },
[1643339389.746744][3171:3176] CHIP:DMG:                        },
[1643339389.746837][3171:3176] CHIP:DMG:
[1643339389.746900][3171:3176] CHIP:DMG:                },
[1643339389.746976][3171:3176] CHIP:DMG:
[1643339389.747034][3171:3176] CHIP:DMG:        ],
[1643339389.747108][3171:3176] CHIP:DMG:
[1643339389.747163][3171:3176] CHIP:DMG: },
[1643339389.747303][3171:3176] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1643339389.747385][3171:3176] CHIP:ZCL: ConnectNetworkResponse:
[1643339389.747439][3171:3176] CHIP:ZCL:   NetworkingStatus: 0
[1643339389.747487][3171:3176] CHIP:ZCL:   DebugText:
[1643339389.747536][3171:3176] CHIP:ZCL:   ErrorValue: 536946472
[1643339389.747591][3171:3176] CHIP:CTL: Received success response 0x0

[1643339389.748586][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339389.749843][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339389.750232][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339389.750860][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339389.752473][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339390.749660][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339390.751277][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339390.751641][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339390.751957][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339392.326344][3171:3176] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1643339392.750200][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339392.751635][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339392.751998][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339392.752323][3171:3176] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339395.107680][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.107778][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.108358][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.109852][3171:3176] CHIP:TOO: Pairing Success
[1643339395.110833][3171:3176] CHIP:IN: Generating DestinationID. Fabric ID 0x0000000000000001, Dest node ID 0x0000000000BC5C01, Random data
[1643339395.110915][3171:3176] CHIP:IN: 0xc7, 0x79, 0x99, 0xcb, 0x3d, 0x3d, 0xbb, 0x20,
[1643339395.110968][3171:3176] CHIP:IN: 0xa3, 0xd0, 0xd2, 0xd8, 0x43, 0x9d, 0x8f, 0x83,
[1643339395.111018][3171:3176] CHIP:IN: 0xc8, 0x0e, 0x62, 0x32, 0xdd, 0xfb, 0x6f, 0xf1,
[1643339395.111066][3171:3176] CHIP:IN: 0x5e, 0xf5, 0x7d, 0xce, 0x45, 0x2b, 0xa3, 0xa6,
[1643339395.111111][3171:3176] CHIP:IN: Root pubkey
[1643339395.111160][3171:3176] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339395.111208][3171:3176] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339395.111256][3171:3176] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339395.111304][3171:3176] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339395.111351][3171:3176] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339395.111398][3171:3176] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339395.111446][3171:3176] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339395.111494][3171:3176] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339395.111536][3171:3176] CHIP:IN: 0xf4,
[1643339395.111579][3171:3176] CHIP:IN: IPK
[1643339395.111627][3171:3176] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
[1643339395.111676][3171:3176] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
[1643339395.111741][3171:3176] CHIP:IN: Generated DestinationID output
[1643339395.111793][3171:3176] CHIP:IN: 0x14, 0x99, 0x58, 0x7f, 0x7a, 0x59, 0x62, 0xc3,
[1643339395.111841][3171:3176] CHIP:IN: 0x1e, 0x11, 0xc8, 0xcf, 0x33, 0x09, 0x9a, 0xd1,
[1643339395.111888][3171:3176] CHIP:IN: 0xbe, 0x85, 0x47, 0x0c, 0xff, 0xa3, 0x92, 0x35,
[1643339395.111936][3171:3176] CHIP:IN: 0xc4, 0x51, 0x20, 0xe9, 0x5e, 0x12, 0xfe, 0x48,
[1643339395.111982][3171:3176] CHIP:SC: Including MRP parameters
[1643339395.112088][3171:3176] CHIP:IN: Prepared plaintext message 0xaaaad0a5f3b0 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 54708i with MessageCounter:4121202570.
[1643339395.112170][3171:3176] CHIP:IN: Sending plaintext msg 0xaaaad0a5f3b0 with MessageCounter:4121202570 to 0x0000000000000000 at monotonic time: 360881 msec
[1643339395.112413][3171:3176] CHIP:SC: Sent Sigma1 msg
[1643339395.112484][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.112721][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.112780][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.112835][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.112882][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.112940][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.113123][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.113258][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.113360][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.113454][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.113563][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.113797][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.113925][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.113984][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.114031][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.114090][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.114268][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.114323][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.114372][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.114416][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.114470][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.114723][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.114779][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.114830][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.114876][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.114936][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.115279][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.115343][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.115390][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.115434][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.115490][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.115648][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.115701][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.115752][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.115796][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.115850][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.115999][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.116048][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.116094][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.116131][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.116186][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.116336][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.116385][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.116433][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.116477][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.116527][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.116676][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.116724][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.116772][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.116815][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.116866][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.117016][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.117064][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.117112][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.117155][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.117205][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.117473][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.117516][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.117540][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.117561][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.117587][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.117663][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.117688][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.117712][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.117733][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.117759][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.117832][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.117857][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.117881][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.117902][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.117928][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.118002][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.118027][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.118051][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.118073][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.118098][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.118172][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.118196][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.118220][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.118242][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.118267][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.118342][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.118366][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.118389][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.118410][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.118436][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.118599][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.118627][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.118651][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.118673][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.118700][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.118775][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.118800][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.118824][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.118845][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.118871][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.118945][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.118970][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.118994][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.119016][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.119041][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.119114][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.119138][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.119162][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.119183][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.119209][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.119282][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.119306][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.119330][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.119352][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.119377][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.119453][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.119477][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.119501][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.119522][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.119547][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.119675][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.119700][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.119724][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.119746][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.119771][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.119848][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.119872][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.119896][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.119918][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.119943][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.120019][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.120044][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.120067][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.120089][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.120114][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.120189][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.120213][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.120237][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.120259][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.120284][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.120374][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.120399][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.120424][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.120446][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.120471][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339395.120548][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339395.120573][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339395.120597][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339395.120618][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339395.120643][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.108099][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.108172][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.108215][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.108251][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.108305][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.108465][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.108508][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.108548][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.108582][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.108625][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.108766][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.108806][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.108845][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.108879][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.108938][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.109146][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.109206][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.109263][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.109314][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.109376][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.109581][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.109639][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.109696][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.109747][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.109808][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.110007][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.110067][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.110134][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.110192][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.110249][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.110686][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.110744][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.110794][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.110838][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.110895][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.111089][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.111138][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.111185][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.111228][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.111279][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.111468][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.111519][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.111567][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.111609][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.111660][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.111846][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.111895][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.111943][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.111986][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.112037][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.112222][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.112271][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.112318][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.112359][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.112409][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.112596][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.112644][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.112691][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.112733][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.112784][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.113107][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.113156][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.113205][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.113247][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.113299][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.113495][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.113545][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.113609][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.113663][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.113726][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.113932][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.113991][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.114047][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.114098][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.114162][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.114371][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.114429][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.114519][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.114575][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.114636][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.114844][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.114903][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.114959][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.115010][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.115070][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.115276][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.115334][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.115390][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.115441][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.115502][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.115845][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.115908][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.115965][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.116017][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.116079][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.116283][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.116340][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.116397][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.116447][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.116507][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.116705][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.116763][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.116819][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.116869][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.116929][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.117126][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.117183][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.117238][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.117289][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.117349][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.117544][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.117613][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.117671][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.117721][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.117781][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.117979][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.118037][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.118093][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.118143][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.118203][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.118660][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.118736][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.118799][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.118854][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.118922][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.119143][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.119204][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.119262][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.119313][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.119374][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.119578][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.119639][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.119699][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.119751][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.119812][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.119973][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.119998][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.120021][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.120041][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.120066][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.120149][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.120174][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.120196][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.120217][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.120241][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339396.120321][3171:3176] CHIP:DIS: Discovered node without a pending query
[1643339396.120345][3171:3176] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339396.120367][3171:3176] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339396.120388][3171:3176] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339396.120412][3171:3176] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339397.326537][3171:3176] CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:4151490779 on exchange 54708i
[1643339397.326644][3171:3176] CHIP:EM: Found matching exchange: 54708i, Delegate: 0xffffb84e6348
[1643339397.326740][3171:3176] CHIP:EM: Rxd Ack; Removing MessageCounter:4121202570 from Retrans Table on exchange 54708i
[1643339397.326822][3171:3176] CHIP:EM: Removed CHIP MessageCounter:4121202570 from RetransTable on exchange 54708i
[1643339397.326911][3171:3176] CHIP:SC: Received Sigma2 msg
[1643339397.326993][3171:3176] CHIP:SC: Peer assigned session session ID 2
[1643339397.332830][3171:3176] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey
[1643339397.332932][3171:3176] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339397.332993][3171:3176] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339397.333052][3171:3176] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339397.333109][3171:3176] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339397.333168][3171:3176] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339397.333225][3171:3176] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339397.333280][3171:3176] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339397.333335][3171:3176] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339397.333385][3171:3176] CHIP:IN: 0xf4,
[1643339397.333505][3171:3176] CHIP:IN: Generated compressed fabric ID
[1643339397.333571][3171:3176] CHIP:IN: 0x8d, 0x53, 0xb2, 0x75, 0x5d, 0x55, 0x94, 0xb6,
[1643339397.335749][3171:3176] CHIP:SC: Found MRP parameters in the message
[1643339397.335986][3171:3176] CHIP:SC: Sending Sigma3
[1643339397.336840][3171:3176] CHIP:EM: Piggybacking Ack for MessageCounter:4151490779 on exchange: 54708i
[1643339397.336946][3171:3176] CHIP:IN: Prepared plaintext message 0xaaaad0a5f3b0 to 0x0000000000000000 (0)  of type 0x32 and protocolId (0, 0) on exchange 54708i with MessageCounter:4121202571.
[1643339397.337033][3171:3176] CHIP:IN: Sending plaintext msg 0xaaaad0a5f3b0 with MessageCounter:4121202571 to 0x0000000000000000 at monotonic time: 363106 msec
[1643339397.337307][3171:3176] CHIP:SC: Sent Sigma3 msg
[1643339397.909991][3171:3176] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:4151490780 on exchange 54708i
[1643339397.910092][3171:3176] CHIP:EM: Found matching exchange: 54708i, Delegate: 0xffffb84e6348
[1643339397.910193][3171:3176] CHIP:EM: Rxd Ack; Removing MessageCounter:4121202571 from Retrans Table on exchange 54708i
[1643339397.910253][3171:3176] CHIP:EM: Removed CHIP MessageCounter:4121202571 from RetransTable on exchange 54708i
[1643339397.910347][3171:3176] CHIP:SC: Success status report received. Session was established
[1643339397.910417][3171:3176] CHIP:IN: New secure session created for device 0x0000000000BC5C01, key 2!!
[1643339397.910685][3171:3176] CHIP:CTL: Calling commissioning complete
[1643339397.910808][3171:3176] CHIP:DMG: ICR moving to [AddingComm]
[1643339397.910873][3171:3176] CHIP:DMG: ICR moving to [AddedComma]
[1643339397.911038][3171:3176] CHIP:IN: Prepared encrypted message 0xaaaad0a5f3b0 to 0x0000000000BC5C01 (1)  of type 0x8 and protocolId (0, 1) on exchange 54709i with MessageCounter:2623612.
[1643339397.911139][3171:3176] CHIP:IN: Sending encrypted msg 0xaaaad0a5f3b0 with MessageCounter:2623612 to 0x0000000000BC5C01 (1) at monotonic time: 363680 msec
[1643339397.911427][3171:3176] CHIP:DMG: ICR moving to [CommandSen]
[1643339397.911518][3171:3176] CHIP:EM: Sending Standalone Ack for MessageCounter:4151490780 on exchange 54708i
[1643339397.911600][3171:3176] CHIP:IN: Prepared plaintext message 0xffffabffd9c8 to 0x0000000000000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 54708i with MessageCounter:4121202572.
[1643339397.911683][3171:3176] CHIP:IN: Sending plaintext msg 0xffffabffd9c8 with MessageCounter:4121202572 to 0x0000000000000000 at monotonic time: 363681 msec
[1643339397.911870][3171:3176] CHIP:EM: Flushed pending ack for MessageCounter:4151490780 on exchange 54708i
[1643339398.064795][3171:3176] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:10996848 on exchange 54709i
[1643339398.064898][3171:3176] CHIP:EM: Found matching exchange: 54709i, Delegate: 0xffffa4004a00
[1643339398.064999][3171:3176] CHIP:EM: Rxd Ack; Removing MessageCounter:2623612 from Retrans Table on exchange 54709i
[1643339398.065050][3171:3176] CHIP:EM: Removed CHIP MessageCounter:2623612 from RetransTable on exchange 54709i
[1643339398.065120][3171:3176] CHIP:DMG: ICR moving to [ResponseRe]
[1643339398.065210][3171:3176] CHIP:DMG: InvokeResponseMessage =
[1643339398.065261][3171:3176] CHIP:DMG: {
[1643339398.065389][3171:3176] CHIP:DMG:        suppressResponse = false,
[1643339398.065574][3171:3176] CHIP:DMG:        InvokeResponseIBs =
[1643339398.065664][3171:3176] CHIP:DMG:        [
[1643339398.065727][3171:3176] CHIP:DMG:                InvokeResponseIB =
[1643339398.065815][3171:3176] CHIP:DMG:                {
[1643339398.066017][3171:3176] CHIP:DMG:                        CommandStatusIB =
[1643339398.066206][3171:3176] CHIP:DMG:                        {
[1643339398.066273][3171:3176] CHIP:DMG:                                CommandPathIB =
[1643339398.066356][3171:3176] CHIP:DMG:                                {
[1643339398.066447][3171:3176] CHIP:DMG:                                        EndpointId = 0x0,
[1643339398.066647][3171:3176] CHIP:DMG:                                        ClusterId = 0x30,
[1643339398.066738][3171:3176] CHIP:DMG:                                        CommandId = 0x4,
[1643339398.066827][3171:3176] CHIP:DMG:                                },
[1643339398.066919][3171:3176] CHIP:DMG:
[1643339398.066992][3171:3176] CHIP:DMG:                                StatusIB =
[1643339398.067071][3171:3176] CHIP:DMG:                                {
[1643339398.067152][3171:3176] CHIP:DMG:                                        status = 0x0,
[1643339398.067231][3171:3176] CHIP:DMG:                                },
[1643339398.067311][3171:3176] CHIP:DMG:
[1643339398.067391][3171:3176] CHIP:DMG:                        },
[1643339398.067472][3171:3176] CHIP:DMG:
[1643339398.067548][3171:3176] CHIP:DMG:                },
[1643339398.067635][3171:3176] CHIP:DMG:
[1643339398.067699][3171:3176] CHIP:DMG:        ],
[1643339398.067770][3171:3176] CHIP:DMG:
[1643339398.067824][3171:3176] CHIP:DMG: },
[1643339398.067962][3171:3176] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 Status=0x0
[1643339398.068024][3171:3176] CHIP:ZCL: DefaultResponse:
[1643339398.068073][3171:3176] CHIP:ZCL:   Transaction: 0xffffa4004a00
[1643339398.068123][3171:3176] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1643339398.068180][3171:3176] CHIP:CTL: Received success response 0x1834

[1643339398.068259][3171:3176] CHIP:CTL: Rendezvous cleanup
[1643339398.068311][3171:3176] CHIP:TOO: Device commissioning completed with success
[1643339398.068425][3171:3176] CHIP:DMG: ICR moving to [AwaitingDe]
[1643339398.068494][3171:3176] CHIP:EM: Sending Standalone Ack for MessageCounter:10996848 on exchange 54709i
[1643339398.068628][3171:3176] CHIP:IN: Prepared encrypted message 0xffffabffd9d8 to 0x0000000000BC5C01 (1)  of type 0x10 and protocolId (0, 0) on exchange 54709i with MessageCounter:2623613.
[1643339398.068719][3171:3176] CHIP:IN: Sending encrypted msg 0xffffabffd9d8 with MessageCounter:2623613 to 0x0000000000BC5C01 (1) at monotonic time: 363838 msec
[1643339398.068970][3171:3176] CHIP:EM: Flushed pending ack for MessageCounter:10996848 on exchange 54709i
[1643339398.069465][3171:3171] CHIP:CTL: Shutting down the commissioner
[1643339398.069718][3171:3171] CHIP:CTL: Shutting down the controller
[1643339398.069822][3171:3171] CHIP:CTL: Shutting down the commissioner
[1643339398.070011][3171:3171] CHIP:CTL: Shutting down the controller
[1643339398.070096][3171:3171] CHIP:CTL: Shutting down the commissioner
[1643339398.070274][3171:3171] CHIP:CTL: Shutting down the controller
[1643339398.070350][3171:3171] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1643339398.073093][3171:3171] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1643339398.073167][3171:3171] CHIP:IN: Clearing BLE pending packets.
[1643339398.073698][3171:3171] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-jvT7nI)
[1643339398.075011][3171:3171] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1643339398.075146][3171:3171] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1643339398.075176][3171:3171] CHIP:DL: Inet Layer shutdown
[1643339398.075200][3171:3171] CHIP:DL: BLE shutdown
[1643339398.075254][3171:3171] CHIP:BLE: Auto-closing end point's BLE connection.
[1643339398.075301][3171:3171] CHIP:DL: Closing BLE GATT connection (con 0xffffb0045220)
[1643339398.075640][3171:3174] CHIP:DL: BluezDisconnect peer=84:71:27:6F:F0:38
[1643339398.077397][3171:3171] CHIP:DL: System Layer shutdown

/chip-tool booleanstate read cluster-revision 12344321 1 fails here:

ubuntu@matter-7-5:~/connectedhomeip/out/standalone$ ./chip-tool booleanstate read cluster-revision 12344321 1
[1643339448.917548][3188:3188] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-0wZPGA)
[1643339448.918210][3188:3188] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1643339448.918269][3188:3188] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
[1643339448.919241][3188:3188] CHIP:DL: Got Ethernet interface: eth0
[1643339448.919857][3188:3188] CHIP:DL: Found the primary Ethernet interface:eth0
[1643339448.920475][3188:3188] CHIP:DL: Got WiFi interface: wlan0
[1643339448.920554][3188:3188] CHIP:DL: Failed to reset WiFi statistic counts
[1643339448.920625][3188:3188] CHIP:IN: UDP::Init bind&listen port=5542
[1643339448.920738][3188:3188] CHIP:IN: UDP::Init bound to port=5542
[1643339448.920765][3188:3188] CHIP:IN: UDP::Init bind&listen port=5542
[1643339448.920853][3188:3188] CHIP:IN: UDP::Init bound to port=5542
[1643339448.920879][3188:3188] CHIP:IN: TransportMgr initialized
[1643339448.920918][3188:3188] CHIP:DIS: Init fabric pairing table with server storage
[1643339448.921206][3188:3188] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Ht1LGK)
[1643339448.921775][3188:3188] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1643339448.921827][3188:3188] CHIP:DL: NVS set: chip-counters/GlobalMCTR = 2000 (0x7D0)
[1643339448.921945][3188:3188] CHIP:ZCL: Using ZAP configuration...
[1643339448.925036][3188:3188] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339448.932346][3188:3188] CHIP:DL: MDNS failed to join multicast group on veth8ac736a for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339448.934275][3188:3188] CHIP:DL: MDNS failed to join multicast group on veth54a3921 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339448.936476][3188:3188] CHIP:DL: MDNS failed to join multicast group on veth1c1f146 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339448.938619][3188:3188] CHIP:DL: MDNS failed to join multicast group on wpan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found
[1643339448.938944][3188:3188] CHIP:CTL: System State Initialized...
[1643339448.941647][3188:3188] CHIP:CTL: Generating NOC
[1643339448.941973][3188:3188] CHIP:CTL: Generating ICAC
[1643339448.943246][3188:3188] CHIP:DIS: Verifying the received credentials
[1643339448.945033][3188:3188] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey
[1643339448.945070][3188:3188] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339448.945095][3188:3188] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339448.945118][3188:3188] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339448.945141][3188:3188] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339448.945164][3188:3188] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339448.945187][3188:3188] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339448.945209][3188:3188] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339448.945232][3188:3188] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339448.945252][3188:3188] CHIP:IN: 0xf4,
[1643339448.945305][3188:3188] CHIP:IN: Generated compressed fabric ID
[1643339448.945330][3188:3188] CHIP:IN: 0x8d, 0x53, 0xb2, 0x75, 0x5d, 0x55, 0x94, 0xb6,
[1643339448.945360][3188:3188] CHIP:DIS: Added new fabric at index: 1, Initialized: 1
[1643339448.945383][3188:3188] CHIP:DIS: Assigned compressed fabric ID: 0x8D53B2755D5594B6, node ID: 0x000000000001B669
[1643339448.945405][3188:3188] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x8D53B2755D5594B6
[1643339448.945476][3188:3188] CHIP:IN: UDP::Init bind&listen port=5550
[1643339448.945610][3188:3188] CHIP:IN: UDP::Init bound to port=5550
[1643339448.945637][3188:3188] CHIP:IN: UDP::Init bind&listen port=5550
[1643339448.945729][3188:3188] CHIP:IN: UDP::Init bound to port=5550
[1643339448.945753][3188:3188] CHIP:IN: TransportMgr initialized
[1643339448.946646][3188:3188] CHIP:CTL: Generating NOC
[1643339448.946982][3188:3188] CHIP:CTL: Generating ICAC
[1643339448.947693][3188:3188] CHIP:DIS: Verifying the received credentials
[1643339448.949417][3188:3188] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000002 and root pubkey
[1643339448.949454][3188:3188] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339448.949479][3188:3188] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339448.949502][3188:3188] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339448.949525][3188:3188] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339448.949548][3188:3188] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339448.949571][3188:3188] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339448.949593][3188:3188] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339448.949616][3188:3188] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339448.949636][3188:3188] CHIP:IN: 0xf4,
[1643339448.949687][3188:3188] CHIP:IN: Generated compressed fabric ID
[1643339448.949712][3188:3188] CHIP:IN: 0x4e, 0xa6, 0x96, 0x46, 0x5f, 0xfc, 0x9b, 0xa0,
[1643339448.949741][3188:3188] CHIP:DIS: Added new fabric at index: 2, Initialized: 1
[1643339448.949764][3188:3188] CHIP:DIS: Assigned compressed fabric ID: 0x4EA696465FFC9BA0, node ID: 0x000000000001B669
[1643339448.949788][3188:3188] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x4EA696465FFC9BA0
[1643339448.949854][3188:3188] CHIP:IN: UDP::Init bind&listen port=5550
[1643339448.949985][3188:3188] CHIP:IN: UDP::Init bound to port=5550
[1643339448.950011][3188:3188] CHIP:IN: UDP::Init bind&listen port=5550
[1643339448.950099][3188:3188] CHIP:IN: UDP::Init bound to port=5550
[1643339448.950123][3188:3188] CHIP:IN: TransportMgr initialized
[1643339448.951190][3188:3188] CHIP:CTL: Generating NOC
[1643339448.951552][3188:3188] CHIP:CTL: Generating ICAC
[1643339448.952367][3188:3188] CHIP:DIS: Verifying the received credentials
[1643339448.954182][3188:3188] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000003 and root pubkey
[1643339448.954232][3188:3188] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339448.954256][3188:3188] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339448.954279][3188:3188] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339448.954302][3188:3188] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339448.954324][3188:3188] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339448.954347][3188:3188] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339448.954370][3188:3188] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339448.954392][3188:3188] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339448.954412][3188:3188] CHIP:IN: 0xf4,
[1643339448.954467][3188:3188] CHIP:IN: Generated compressed fabric ID
[1643339448.954515][3188:3188] CHIP:IN: 0x6a, 0xd6, 0x18, 0xf2, 0xf7, 0x73, 0xdf, 0x14,
[1643339448.954547][3188:3188] CHIP:DIS: Added new fabric at index: 3, Initialized: 1
[1643339448.954570][3188:3188] CHIP:DIS: Assigned compressed fabric ID: 0x6AD618F2F773DF14, node ID: 0x000000000001B669
[1643339448.954593][3188:3188] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x6AD618F2F773DF14
[1643339448.954688][3188:3188] CHIP:IN: UDP::Init bind&listen port=5550
[1643339448.954825][3188:3188] CHIP:IN: UDP::Init bound to port=5550
[1643339448.954852][3188:3188] CHIP:IN: UDP::Init bind&listen port=5550
[1643339448.954941][3188:3188] CHIP:IN: UDP::Init bound to port=5550
[1643339448.954965][3188:3188] CHIP:IN: TransportMgr initialized
[1643339448.955291][3188:3193] CHIP:DL: CHIP task running
[1643339448.955422][3188:3193] CHIP:TOO: Sending command to node 0xbc5c01
[1643339448.956088][3188:3193] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339448.956681][3188:3193] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339448.956974][3188:3193] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339448.957114][3188:3193] CHIP:DIS: Attempt to mDNS broadcast failed:  ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable
[1643339448.957937][3188:3193] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339448.957990][3188:3193] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339448.958018][3188:3193] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339448.959605][3188:3193] CHIP:IN: Generating DestinationID. Fabric ID 0x0000000000000001, Dest node ID 0x0000000000BC5C01, Random data
[1643339448.959661][3188:3193] CHIP:IN: 0xc7, 0xd4, 0x8b, 0xeb, 0x28, 0x67, 0x3a, 0xb5,
[1643339448.959686][3188:3193] CHIP:IN: 0xc2, 0x6b, 0x85, 0x8d, 0xf2, 0x19, 0xe5, 0xf6,
[1643339448.959711][3188:3193] CHIP:IN: 0x1b, 0xfe, 0x26, 0x28, 0x96, 0x72, 0xf6, 0x52,
[1643339448.959736][3188:3193] CHIP:IN: 0x87, 0x80, 0x37, 0x47, 0xb6, 0xa0, 0xbe, 0x57,
[1643339448.959759][3188:3193] CHIP:IN: Root pubkey
[1643339448.959784][3188:3193] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339448.959809][3188:3193] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339448.959834][3188:3193] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339448.959858][3188:3193] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339448.959882][3188:3193] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339448.959906][3188:3193] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339448.959930][3188:3193] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339448.959954][3188:3193] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339448.959976][3188:3193] CHIP:IN: 0xf4,
[1643339448.959998][3188:3193] CHIP:IN: IPK
[1643339448.960023][3188:3193] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
[1643339448.960048][3188:3193] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
[1643339448.960086][3188:3193] CHIP:IN: Generated DestinationID output
[1643339448.960112][3188:3193] CHIP:IN: 0x6b, 0xad, 0x4d, 0x99, 0xc8, 0xbd, 0x57, 0xbe,
[1643339448.960136][3188:3193] CHIP:IN: 0x3a, 0x9e, 0xd1, 0x1c, 0xac, 0x17, 0xea, 0x35,
[1643339448.960161][3188:3193] CHIP:IN: 0xd2, 0xac, 0x20, 0xcf, 0x82, 0xc5, 0x28, 0x54,
[1643339448.960185][3188:3193] CHIP:IN: 0xfd, 0x26, 0x0b, 0xeb, 0xe8, 0x1d, 0x23, 0x95,
[1643339448.960209][3188:3193] CHIP:SC: Including MRP parameters
[1643339448.960279][3188:3193] CHIP:IN: Prepared plaintext message 0xaaab20d0b810 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 9737i with MessageCounter:3664590991.
[1643339448.960324][3188:3193] CHIP:IN: Sending plaintext msg 0xaaab20d0b810 with MessageCounter:3664590991 to 0x0000000000000000 at monotonic time: 414729 msec
[1643339448.960481][3188:3193] CHIP:SC: Sent Sigma1 msg
[1643339448.960518][3188:3193] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339448.960862][3188:3193] CHIP:DIS: Discovered node without a pending query
[1643339448.960893][3188:3193] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339448.960922][3188:3193] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339448.960947][3188:3193] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339448.960978][3188:3193] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339448.961137][3188:3193] CHIP:DIS: Discovered node without a pending query
[1643339448.961163][3188:3193] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339448.961188][3188:3193] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339448.961211][3188:3193] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339448.961238][3188:3193] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339448.961391][3188:3193] CHIP:DIS: Discovered node without a pending query
[1643339448.961418][3188:3193] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339448.961443][3188:3193] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339448.961466][3188:3193] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339448.961493][3188:3193] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339448.961645][3188:3193] CHIP:DIS: Discovered node without a pending query
[1643339448.961672][3188:3193] CHIP:DIS: Node ID resolved for 0x0000000000BC5C01
[1643339448.961697][3188:3193] CHIP:DIS:     Addr 0: [2001:db8::7dfa:e693:a110:a82]:5540
[1643339448.961720][3188:3193] CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000BC5C01
[1643339448.961746][3188:3193] CHIP:CTL: Address resolved for node: 0x0000000000BC5C01
[1643339451.076382][3188:3193] CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:4151490781 on exchange 9737i
[1643339451.076485][3188:3193] CHIP:EM: Found matching exchange: 9737i, Delegate: 0xffff806bd348
[1643339451.076577][3188:3193] CHIP:EM: Rxd Ack; Removing MessageCounter:3664590991 from Retrans Table on exchange 9737i
[1643339451.076639][3188:3193] CHIP:EM: Removed CHIP MessageCounter:3664590991 from RetransTable on exchange 9737i
[1643339451.076730][3188:3193] CHIP:SC: Received Sigma2 msg
[1643339451.076814][3188:3193] CHIP:SC: Peer assigned session session ID 3
[1643339451.082652][3188:3193] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey
[1643339451.082748][3188:3193] CHIP:IN: 0x04, 0x16, 0x30, 0x4e, 0x0a, 0x4b, 0x43, 0x9a,
[1643339451.082810][3188:3193] CHIP:IN: 0x48, 0x79, 0xa2, 0x72, 0xcb, 0xd9, 0xaf, 0xb4,
[1643339451.082870][3188:3193] CHIP:IN: 0x55, 0xc3, 0x42, 0x14, 0x36, 0x30, 0x8b, 0xf0,
[1643339451.082930][3188:3193] CHIP:IN: 0x75, 0x67, 0xdf, 0x0f, 0xa7, 0x28, 0x45, 0x18,
[1643339451.082989][3188:3193] CHIP:IN: 0xb4, 0x9d, 0xfc, 0x05, 0x4c, 0xf2, 0x52, 0x09,
[1643339451.083046][3188:3193] CHIP:IN: 0x66, 0xb4, 0x20, 0x58, 0xec, 0xac, 0xb7, 0x7b,
[1643339451.083102][3188:3193] CHIP:IN: 0x04, 0x9d, 0xcd, 0x3f, 0xaa, 0x49, 0x32, 0xd2,
[1643339451.083158][3188:3193] CHIP:IN: 0xae, 0x55, 0x6b, 0x31, 0x13, 0x36, 0x24, 0x0d,
[1643339451.083209][3188:3193] CHIP:IN: 0xf4,
[1643339451.083358][3188:3193] CHIP:IN: Generated compressed fabric ID
[1643339451.083425][3188:3193] CHIP:IN: 0x8d, 0x53, 0xb2, 0x75, 0x5d, 0x55, 0x94, 0xb6,
[1643339451.085572][3188:3193] CHIP:SC: Found MRP parameters in the message
[1643339451.085671][3188:3193] CHIP:SC: Sending Sigma3
[1643339451.086638][3188:3193] CHIP:EM: Piggybacking Ack for MessageCounter:4151490781 on exchange: 9737i
[1643339451.086736][3188:3193] CHIP:IN: Prepared plaintext message 0xaaab20d0b810 to 0x0000000000000000 (0)  of type 0x32 and protocolId (0, 0) on exchange 9737i with MessageCounter:3664590992.
[1643339451.086824][3188:3193] CHIP:IN: Sending plaintext msg 0xaaab20d0b810 with MessageCounter:3664590992 to 0x0000000000000000 at monotonic time: 416856 msec
[1643339451.087105][3188:3193] CHIP:SC: Sent Sigma3 msg
[1643339451.572298][3188:3193] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:4151490782 on exchange 9737i
[1643339451.572401][3188:3193] CHIP:EM: Found matching exchange: 9737i, Delegate: 0xffff806bd348
[1643339451.572497][3188:3193] CHIP:EM: Rxd Ack; Removing MessageCounter:3664590992 from Retrans Table on exchange 9737i
[1643339451.572561][3188:3193] CHIP:EM: Removed CHIP MessageCounter:3664590992 from RetransTable on exchange 9737i
[1643339451.572648][3188:3193] CHIP:SC: Success status report received. Session was established
[1643339451.572721][3188:3193] CHIP:IN: New secure session created for device 0x0000000000BC5C01, key 3!!
[1643339451.572951][3188:3193] CHIP:TOO: Sending cluster (0x0045) command (0x00) on endpoint 1
[1643339451.573010][3188:3193] CHIP:DMG: SendReadRequest ReadClient[0xffff6c001950]: Sending Read Request
[1643339451.573126][3188:3193] CHIP:IN: Prepared encrypted message 0xaaab20d0b810 to 0x0000000000BC5C01 (1)  of type 0x2 and protocolId (0, 1) on exchange 9738i with MessageCounter:9737011.
[1643339451.573167][3188:3193] CHIP:IN: Sending encrypted msg 0xaaab20d0b810 with MessageCounter:9737011 to 0x0000000000BC5C01 (1) at monotonic time: 417342 msec
[1643339451.573319][3188:3193] CHIP:DMG: MoveToState ReadClient[0xffff6c001950]: Moving to [AwaitingIn]
[1643339451.573363][3188:3193] CHIP:CTL: Device connected callback with null pairing delegate. Ignoring
[1643339451.573389][3188:3193] CHIP:EM: Sending Standalone Ack for MessageCounter:4151490782 on exchange 9737i
[1643339451.573422][3188:3193] CHIP:IN: Prepared plaintext message 0xffff73ffd9c8 to 0x0000000000000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 9737i with MessageCounter:3664590993.
[1643339451.573454][3188:3193] CHIP:IN: Sending plaintext msg 0xffff73ffd9c8 with MessageCounter:3664590993 to 0x0000000000000000 at monotonic time: 417342 msec
[1643339451.573551][3188:3193] CHIP:EM: Flushed pending ack for MessageCounter:4151490782 on exchange 9737i
[1643339451.667014][3188:3193] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:9925204 on exchange 9738i
[1643339451.667119][3188:3193] CHIP:EM: Found matching exchange: 9738i, Delegate: 0xffff6c001950
[1643339451.667217][3188:3193] CHIP:EM: Rxd Ack; Removing MessageCounter:9737011 from Retrans Table on exchange 9738i
[1643339451.667279][3188:3193] CHIP:EM: Removed CHIP MessageCounter:9737011 from RetransTable on exchange 9738i
[1643339451.667404][3188:3193] CHIP:DMG: ReportDataMessage =
[1643339451.667474][3188:3193] CHIP:DMG: {
[1643339451.667527][3188:3193] CHIP:DMG:        AttributeReportIBs =
[1643339451.667604][3188:3193] CHIP:DMG:        [
[1643339451.667665][3188:3193] CHIP:DMG:                AttributeReportIB =
[1643339451.667747][3188:3193] CHIP:DMG:                {
[1643339451.667813][3188:3193] CHIP:DMG:                        AttributeStatusIB =
[1643339451.667894][3188:3193] CHIP:DMG:                        {
[1643339451.667965][3188:3193] CHIP:DMG:                                AttributePathIB =
[1643339451.668041][3188:3193] CHIP:DMG:                                {
[1643339451.668119][3188:3193] CHIP:DMG:                                        Endpoint = 0x1,
[1643339451.668204][3188:3193] CHIP:DMG:                                        Cluster = 0x45,
[1643339451.668286][3188:3193] CHIP:DMG:                                        Attribute = 0x0000_FFFD,
[1643339451.668362][3188:3193] CHIP:DMG:                                }
[1643339451.668447][3188:3193] CHIP:DMG:
[1643339451.668522][3188:3193] CHIP:DMG:                                StatusIB =
[1643339451.668596][3188:3193] CHIP:DMG:                                {
[1643339451.668671][3188:3193] CHIP:DMG:                                        status = 0x86,
[1643339451.668746][3188:3193] CHIP:DMG:                                },
[1643339451.668822][3188:3193] CHIP:DMG:
[1643339451.668890][3188:3193] CHIP:DMG:                        },
[1643339451.668970][3188:3193] CHIP:DMG:
[1643339451.669036][3188:3193] CHIP:DMG:                },
[1643339451.669113][3188:3193] CHIP:DMG:
[1643339451.669173][3188:3193] CHIP:DMG:        ],
[1643339451.669248][3188:3193] CHIP:DMG:
[1643339451.669308][3188:3193] CHIP:DMG:        SuppressResponse = true,
[1643339451.669367][3188:3193] CHIP:DMG: }
[1643339451.671074][3188:3193] CHIP:TOO: Default Failure Response: 0x86
[1643339451.671247][3188:3193] CHIP:EM: Sending Standalone Ack for MessageCounter:9925204 on exchange 9738i
[1643339451.671393][3188:3193] CHIP:IN: Prepared encrypted message 0xffff73ffd9d8 to 0x0000000000BC5C01 (1)  of type 0x10 and protocolId (0, 0) on exchange 9738i with MessageCounter:9737012.
[1643339451.671484][3188:3193] CHIP:IN: Sending encrypted msg 0xffff73ffd9d8 with MessageCounter:9737012 to 0x0000000000BC5C01 (1) at monotonic time: 417441 msec
[1643339451.671723][3188:3193] CHIP:EM: Flushed pending ack for MessageCounter:9925204 on exchange 9738i
[1643339451.672077][3188:3188] CHIP:-: ../../examples/chip-tool/third_party/connectedhomeip/zzz_generated/chip-tool/zap-generated/cluster/Commands.h:2502: CHIP Error 0x000000AC: Internal error at ../../examples/chip-tool/commands/common/CHIPCommand.cpp:59
[1643339451.672165][3188:3188] CHIP:TOO: Run command failure: ../../examples/chip-tool/third_party/connectedhomeip/zzz_generated/chip-tool/zap-generated/cluster/Commands.h:2502: CHIP Error 0x000000AC: Internal error
[1643339451.678877][3188:3188] CHIP:SPT: VerifyOrDie failure at ../../examples/chip-tool/third_party/connectedhomeip/src/inet/InetLayer.h:121: sEndPointPool.Allocated() == 0
Aborted (core dumped)
ubuntu@matter-7-5:~/connectedhomeip/out/standalone$

@andy31415
Copy link
Contributor

Seems like a duplicate of #14472 but with a different test case run.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants