(python_env) ubuntu@ubuntuservercontroller:~/matter_te6$ chip-device-ctrl -n 8888 [1634068352.705956][80880:80880] CHIP:CTL: SyncSetKeyValue on ExampleOpCredsCAKey [1634068352.706247][80880:80880] CHIP:CTL: SyncSetKeyValue on ExampleOpCredsICAKey [1634068352.706506][80880:80880] CHIP:CTL: Generating NOC [1634068352.706844][80880:80880] CHIP:CTL: Generating ICAC [1634068352.707084][80880:80880] CHIP:CTL: Generating RCAC [1634068352.707326][80880:80880] CHIP:CTL: SyncSetKeyValue on ExampleCARootCert0 [1634068352.713256][80880:80880] CHIP:IN: UDP::Init bind&listen port=0 [1634068352.713398][80880:80880] CHIP:IN: UDP::Init bound to port=59348 [1634068352.713426][80880:80880] CHIP:IN: UDP::Init bind&listen port=0 [1634068352.713517][80880:80880] CHIP:IN: UDP::Init bound to port=58992 [1634068352.713543][80880:80880] CHIP:IN: TransportMgr initialized [1634068352.713564][80880:80880] CHIP:DIS: Init fabric pairing table with server storage [1634068352.718867][80880:80880] CHIP:DL: Avahi client registered [1634068352.720176][80880:80880] CHIP:ZCL: Using ZAP configuration... [1634068352.720279][80880:80880] CHIP:ZCL: deactivate report event [1634068352.721015][80880:80880] CHIP:DIS: Verifying the received credentials [1634068352.723311][80880:80880] CHIP:DIS: Added new fabric at index: 1, Initialized: 1 [1634068352.723351][80880:80880] CHIP:DIS: Assigned compressed fabric ID: 0x3056BB80A3B83B36, node ID: 0x00000000000022B8 [1634068352.723380][80880:80880] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x3056BB80A3B83B36 [1634068352.738114][80880:80888] CHIP:DL: Platform main loop started. Chip Device Controller Shell chip-device-ctrl > connect -ble 3840 73141520 101 Device is assigned with nodeid = 101 [1634068353.793939][80880:80888] CHIP:SC: Assigned local session key ID 1 [1634068353.794184][80880:80888] CHIP:IN: Build plaintext message 0xffffa8ff21e0 to 0x0000000000000000 of type 32 and protocolId 0 on exchange 3526r with MessageCounter 2494542294. [1634068353.794280][80880:80888] CHIP:IN: Sending plaintext msg 0xffffa8ff21e0 to 0x0000000000000000 at utc time: 10130566 msec [1634068353.794395][80880:80888] CHIP:IN: Sending msg on generic transport [1634068353.794455][80880:80888] CHIP:IN: Message appended to BLE send queue [1634068353.794512][80880:80888] CHIP:SC: Sent PBKDF param request [1634068353.794619][80880:80888] CHIP:CTL: SyncSetKeyValue on StartKeyID [1634068353.795317][80880:80899] CHIP:DL: TRACE: Bluez mainloop starting Thread [1634068353.796080][80880:80884] CHIP:DL: TRACE: Bus acquired for name C-3bf0 [1634068353.804702][80880:80888] CHIP:DL: PlatformBlueZInit init success [1634068353.809962][80880:80884] CHIP:BLE: BLE removing known devices. [1634068353.811931][80880:80884] CHIP:BLE: BLE initiating scan. [1634068354.290957][80880:80884] CHIP:BLE: Device 42:72:11:3C:EB:EF does not look like a CHIP device. [1634068354.360690][80880:80884] CHIP:BLE: Device 66:C5:2A:C8:C0:0E does not look like a CHIP device. [1634068354.364783][80880:80884] CHIP:BLE: Device 68:71:DE:29:29:09 does not look like a CHIP device. [1634068354.369263][80880:80884] CHIP:BLE: Device 61:3D:53:74:F6:F5 does not look like a CHIP device. [1634068354.426059][80880:80884] CHIP:BLE: New device scanned: 00:0D:6F:20:C0:D0 [1634068354.426143][80880:80884] CHIP:BLE: Device discriminator match. Attempting to connect. [1634068354.431012][80880:80884] CHIP:BLE: Scan complete notification without an active scan. [1634068354.763128][80880:80884] CHIP:DL: ConnectDevice complete [1634068355.417589][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417643][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417677][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0001 [1634068355.417698][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417721][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0001 [1634068355.417742][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417765][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0001 [1634068355.417785][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417812][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0001 [1634068355.417832][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417855][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0001 [1634068355.417874][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417897][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0001 [1634068355.417921][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417947][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service000e [1634068355.417968][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.417991][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service000e [1634068355.418010][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418032][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service000e [1634068355.418051][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418079][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service000e [1634068355.418099][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418122][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service000e [1634068355.418142][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418164][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service000e [1634068355.418184][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418219][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418240][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418265][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418284][80880:80884] CHIP:DL: Char1 /org/bluez/hci0/dev_00_0D_6F_20_C0_D0/service0015 [1634068355.418314][80880:80884] CHIP:DL: New BLE connection 0xffffa0043580, device 00:0D:6F:20:C0:D0, path /org/bluez/hci0/dev_00_0D_6F_20_C0_D0 [1634068355.418440][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16385 [1634068355.418480][80880:80888] CHIP:IN: BleConnectionComplete: endPoint 0xffffac761ae0 [1634068356.174746][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068356.472429][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1634068356.472525][80880:80888] CHIP:BLE: subscribe complete, ep = 0xffffac761ae0 [1634068356.476800][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068356.477078][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068356.477215][80880:80888] CHIP:BLE: peripheral chose BTP version 3; central expected between 2 and 3 [1634068356.477266][80880:80888] CHIP:BLE: using BTP fragment sizes rx 20 / tx 128. [1634068356.477377][80880:80888] CHIP:BLE: local and remote recv window size = 3 [1634068356.477558][80880:80888] CHIP:IN: BLE EndPoint 0xffffac761ae0 Connection Complete [1634068356.613818][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068356.763909][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068356.764439][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068356.768906][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068356.769387][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068356.857218][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068356.860478][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068356.860685][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068356.864242][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068356.864483][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.004621][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068357.007445][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.007639][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.010840][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.011050][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.149709][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068357.153034][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.153246][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.153413][80880:80888] CHIP:EM: Received message of type 0x21 with vendorId 0x0000 and protocolId 0x0000 on exchange 3526i [1634068357.153561][80880:80888] CHIP:SC: Received PBKDF param response [1634068357.153656][80880:80888] CHIP:SC: Peer assigned session ID 0 [1634068357.157233][80880:80888] CHIP:IN: Build plaintext message 0xffffa8ff2a10 to 0x0000000000000000 of type 34 and protocolId 0 on exchange 3526r with MessageCounter 2494542295. [1634068357.157331][80880:80888] CHIP:IN: Sending plaintext msg 0xffffa8ff2a10 to 0x0000000000000000 at utc time: 10133929 msec [1634068357.157376][80880:80888] CHIP:IN: Sending msg on generic transport [1634068357.157532][80880:80888] CHIP:SC: Sent spake2p msg1 [1634068357.296361][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068357.300287][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.300857][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.640596][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.640819][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.735209][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068357.740040][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.740316][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.744585][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.744858][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.979051][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068357.982894][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.983131][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068357.987776][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068357.988050][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068358.222456][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068358.226012][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068358.226250][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068358.230399][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068358.230609][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068358.230937][80880:80888] CHIP:EM: Received message of type 0x23 with vendorId 0x0000 and protocolId 0x0000 on exchange 3526i [1634068358.231044][80880:80888] CHIP:SC: Received spake2p msg2 [1634068358.232920][80880:80888] CHIP:IN: Build plaintext message 0xffffa8ff2af0 to 0x0000000000000000 of type 36 and protocolId 0 on exchange 3526r with MessageCounter 2494542296. [1634068358.232987][80880:80888] CHIP:IN: Sending plaintext msg 0xffffa8ff2af0 to 0x0000000000000000 at utc time: 10135005 msec [1634068358.233014][80880:80888] CHIP:IN: Sending msg on generic transport [1634068358.233053][80880:80888] CHIP:SC: Sent spake2p msg3 [1634068358.515058][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068358.661341][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068358.664907][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068358.665132][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068358.668856][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068358.669106][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068358.758758][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068358.762771][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068358.763020][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068358.763245][80880:80888] CHIP:EM: Received message of type 0x40 with vendorId 0x0000 and protocolId 0x0000 on exchange 3526i [1634068358.763393][80880:80888] CHIP:IN: New secure session created for device 0x0000000000000065, key 0!! [1634068358.763577][80880:80888] CHIP:CTL: Remote device completed SPAKE2+ handshake [1634068358.763636][80880:80888] CHIP:CTL: Sending OpCSR request to 0x120ad790 device [1634068358.763757][80880:80888] CHIP:DMG: ICR moving to [Initialize] [1634068358.763900][80880:80888] CHIP:DMG: ICR moving to [AddCommand] [1634068358.764112][80880:80888] CHIP:IN: Secure message was encrypted: Msg ID 0 [1634068358.764180][80880:80888] CHIP:IN: Build encrypted message 0xffffa8ff2850 to 0x0000000000000065 of type 8 and protocolId 1 on exchange 3527r with MessageCounter 0. [1634068358.764255][80880:80888] CHIP:IN: Sending encrypted msg 0xffffa8ff2850 to 0x0000000000000065 at utc time: 10135536 msec [1634068358.764317][80880:80888] CHIP:IN: Sending msg on generic transport [1634068358.764498][80880:80888] CHIP:DMG: ICR moving to [ Sending] [1634068358.764561][80880:80888] CHIP:CTL: Sent OpCSR request, waiting for the CSR [1634068358.953758][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068358.956826][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068358.957031][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.201782][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.202063][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.393311][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068359.396493][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.396700][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.400244][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.400444][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.489972][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068359.494268][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.494534][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.500134][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.500401][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.587255][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068359.590643][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.590867][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.594552][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.594767][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.684764][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068359.688002][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.688212][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.691643][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.691824][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.782984][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068359.787285][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.787690][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.791967][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.792199][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.929015][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068359.932873][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.933155][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068359.937945][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068359.938189][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.026609][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068360.030080][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.030297][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.034236][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.034467][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.123976][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068360.127989][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.128476][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.132600][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.132761][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.221054][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068360.225310][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.225783][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.226129][80880:80888] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 3527i [1634068360.226332][80880:80888] CHIP:DMG: InvokeCommand = [1634068360.226396][80880:80888] CHIP:DMG: { [1634068360.226463][80880:80888] CHIP:DMG: CommandList = [1634068360.226551][80880:80888] CHIP:DMG: [ [1634068360.226607][80880:80888] CHIP:DMG: CommandDataElement = [1634068360.226673][80880:80888] CHIP:DMG: { [1634068360.226786][80880:80888] CHIP:DMG: CommandPath = [1634068360.226878][80880:80888] CHIP:DMG: { [1634068360.227042][80880:80888] CHIP:DMG: EndpointId = 0x0, [1634068360.227134][80880:80888] CHIP:DMG: ClusterId = 0x3e, [1634068360.227258][80880:80888] CHIP:DMG: CommandId = 0x5, [1634068360.227376][80880:80888] CHIP:DMG: }, [1634068360.227503][80880:80888] CHIP:DMG: [1634068360.227573][80880:80888] CHIP:DMG: CommandData = [1634068360.227647][80880:80888] CHIP:DMG: { [1634068360.227723][80880:80888] CHIP:DMG: 0x0 = [ [1634068360.227904][80880:80888] CHIP:DMG: 0x15, 0x30, 0x1, 0xcc, 0x30, 0x81, 0xc9, 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, [1634068360.227997][80880:80888] CHIP:DMG: ] [1634068360.228070][80880:80888] CHIP:DMG: 0x1 = [ [1634068360.228143][80880:80888] CHIP:DMG: [1634068360.228219][80880:80888] CHIP:DMG: ] [1634068360.228298][80880:80888] CHIP:DMG: }, [1634068360.228372][80880:80888] CHIP:DMG: }, [1634068360.228448][80880:80888] CHIP:DMG: [1634068360.228503][80880:80888] CHIP:DMG: ], [1634068360.228572][80880:80888] CHIP:DMG: [1634068360.228623][80880:80888] CHIP:DMG: } [1634068360.228754][80880:80888] CHIP:ZCL: Received Cluster Command: Cluster=3e Command=5 Endpoint=0 [1634068360.228826][80880:80888] CHIP:ZCL: OpCSRResponse: [1634068360.228875][80880:80888] CHIP:ZCL: NOCSRElements: 253 [1634068360.228920][80880:80888] CHIP:ZCL: AttestationSignature: 0 [1634068360.228973][80880:80888] CHIP:CTL: Received certificate signing request from the device [1634068360.229021][80880:80888] CHIP:CTL: Getting certificate chain for the device from the issuer [1634068360.229068][80880:80888] CHIP:CTL: Verifying Certificate Signing Request [1634068360.230713][80880:80888] CHIP:CTL: Generating NOC [1634068360.231552][80880:80888] CHIP:CTL: Generating ICAC [1634068360.232178][80880:80888] CHIP:CTL: Providing certificate chain to the commissioner [1634068360.232245][80880:80888] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:183: Success [1634068360.232426][80880:80888] CHIP:CTL: Sending root certificate to the device [1634068360.232545][80880:80888] CHIP:DMG: ICR moving to [Initialize] [1634068360.232587][80880:80888] CHIP:DMG: ICR moving to [AddCommand] [1634068360.232732][80880:80888] CHIP:IN: Secure message was encrypted: Msg ID 1 [1634068360.232762][80880:80888] CHIP:IN: Build encrypted message 0xffffa8ff1fc0 to 0x0000000000000065 of type 8 and protocolId 1 on exchange 3528r with MessageCounter 1. [1634068360.232799][80880:80888] CHIP:IN: Sending encrypted msg 0xffffa8ff1fc0 to 0x0000000000000065 at utc time: 10137004 msec [1634068360.232826][80880:80888] CHIP:IN: Sending msg on generic transport [1634068360.232944][80880:80888] CHIP:DMG: ICR moving to [ Sending] [1634068360.232974][80880:80888] CHIP:CTL: Sent root certificate to the device [1634068360.233263][80880:80888] CHIP:DMG: ICR moving to [Uninitiali] [1634068360.318632][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068360.322127][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.322564][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.513847][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068360.660208][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068360.663939][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.664427][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.668993][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.669259][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.757692][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068360.761378][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.761617][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.765591][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.765814][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.855094][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068360.859043][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068360.859290][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068360.859553][80880:80888] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 3528i [1634068360.859705][80880:80888] CHIP:DMG: InvokeCommand = [1634068360.859780][80880:80888] CHIP:DMG: { [1634068360.859823][80880:80888] CHIP:DMG: CommandList = [1634068360.859930][80880:80888] CHIP:DMG: [ [1634068360.859979][80880:80888] CHIP:DMG: CommandDataElement = [1634068360.860042][80880:80888] CHIP:DMG: { [1634068360.860106][80880:80888] CHIP:DMG: CommandPath = [1634068360.860176][80880:80888] CHIP:DMG: { [1634068360.860250][80880:80888] CHIP:DMG: EndpointId = 0x0, [1634068360.860336][80880:80888] CHIP:DMG: ClusterId = 0x3e, [1634068360.860408][80880:80888] CHIP:DMG: CommandId = 0xb, [1634068360.860487][80880:80888] CHIP:DMG: }, [1634068360.860559][80880:80888] CHIP:DMG: [1634068360.860620][80880:80888] CHIP:DMG: StatusElement = [1634068360.860705][80880:80888] CHIP:DMG: { [1634068360.860774][80880:80888] CHIP:DMG: GeneralCode = 0x0, [1634068360.860861][80880:80888] CHIP:DMG: ProtocolId = 0x1, [1634068360.860941][80880:80888] CHIP:DMG: protocolCode = 0x0, [1634068360.861011][80880:80888] CHIP:DMG: }, [1634068360.861086][80880:80888] CHIP:DMG: [1634068360.861150][80880:80888] CHIP:DMG: }, [1634068360.861228][80880:80888] CHIP:DMG: [1634068360.861283][80880:80888] CHIP:DMG: ], [1634068360.861353][80880:80888] CHIP:DMG: [1634068360.861403][80880:80888] CHIP:DMG: } SetCommandIndexStatus commandHandle=1 commandIndex=1 [1634068360.862303][80880:80888] CHIP:ZCL: DefaultResponse: [1634068360.862364][80880:80888] CHIP:ZCL: Transaction: 0xffffac75e4f0 [1634068360.862412][80880:80888] CHIP:ZCL: status: EMBER_ZCL_STATUS_SUCCESS (0x00) [1634068360.862471][80880:80888] CHIP:CTL: Device confirmed that it has received the root certificate [1634068360.862516][80880:80888] CHIP:CTL: Sending operational certificate chain to the device [1634068360.862621][80880:80888] CHIP:DMG: ICR moving to [Initialize] [1634068360.862714][80880:80888] CHIP:DMG: ICR moving to [AddCommand] [1634068360.863011][80880:80888] CHIP:IN: Secure message was encrypted: Msg ID 2 [1634068360.863079][80880:80888] CHIP:IN: Build encrypted message 0xffffa8ff2370 to 0x0000000000000065 of type 8 and protocolId 1 on exchange 3529r with MessageCounter 2. [1634068360.863159][80880:80888] CHIP:IN: Sending encrypted msg 0xffffa8ff2370 to 0x0000000000000065 at utc time: 10137635 msec [1634068360.863216][80880:80888] CHIP:IN: Sending msg on generic transport [1634068360.863416][80880:80888] CHIP:DMG: ICR moving to [ Sending] [1634068360.863475][80880:80888] CHIP:CTL: Sent operational certificate to the device [1634068360.863652][80880:80888] CHIP:DMG: ICR moving to [Uninitiali] [1634068361.001043][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068361.004179][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068361.004387][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068361.147568][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068361.244887][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068361.246968][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068361.247142][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068361.342568][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068361.440130][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068361.444081][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068361.444732][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068361.883278][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068361.883556][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068361.976559][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068361.980428][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068361.981077][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068361.985960][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068361.986266][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068362.122752][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068362.126344][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068362.126569][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068362.126900][80880:80888] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 3529i [1634068362.127077][80880:80888] CHIP:DMG: InvokeCommand = [1634068362.127132][80880:80888] CHIP:DMG: { [1634068362.127176][80880:80888] CHIP:DMG: CommandList = [1634068362.127296][80880:80888] CHIP:DMG: [ [1634068362.127347][80880:80888] CHIP:DMG: CommandDataElement = [1634068362.127407][80880:80888] CHIP:DMG: { [1634068362.127460][80880:80888] CHIP:DMG: CommandPath = [1634068362.127568][80880:80888] CHIP:DMG: { [1634068362.127647][80880:80888] CHIP:DMG: EndpointId = 0x0, [1634068362.127754][80880:80888] CHIP:DMG: ClusterId = 0x3e, [1634068362.127909][80880:80888] CHIP:DMG: CommandId = 0x8, [1634068362.127970][80880:80888] CHIP:DMG: }, [1634068362.128074][80880:80888] CHIP:DMG: [1634068362.128120][80880:80888] CHIP:DMG: CommandData = [1634068362.128228][80880:80888] CHIP:DMG: { [1634068362.128366][80880:80888] CHIP:DMG: 0x0 = 0, [1634068362.128510][80880:80888] CHIP:DMG: 0x1 = 1, [1634068362.128585][80880:80888] CHIP:DMG: 0x2 = [ [1634068362.128654][80880:80888] CHIP:DMG: [1634068362.128718][80880:80888] CHIP:DMG: ] [1634068362.128781][80880:80888] CHIP:DMG: }, [1634068362.128845][80880:80888] CHIP:DMG: }, [1634068362.128911][80880:80888] CHIP:DMG: [1634068362.128958][80880:80888] CHIP:DMG: ], [1634068362.129017][80880:80888] CHIP:DMG: [1634068362.129060][80880:80888] CHIP:DMG: } [1634068362.129148][80880:80888] CHIP:ZCL: Received Cluster Command: Cluster=3e Command=8 Endpoint=0 [1634068362.129411][80880:80888] CHIP:ZCL: NOCResponse: [1634068362.129477][80880:80888] CHIP:ZCL: StatusCode: 0 [1634068362.129515][80880:80888] CHIP:ZCL: FabricIndex: 1 [1634068362.129553][80880:80888] CHIP:ZCL: DebugText: 0 [1634068362.129626][80880:80888] CHIP:CTL: Device returned status 0 on receiving the NOC [1634068362.129711][80880:80888] CHIP:CTL: Operational credentials provisioned on device 0x120ad790 [1634068362.129901][80880:80888] CHIP:CTL: SyncSetKeyValue on PairedDevice65 [1634068362.130045][80880:80888] CHIP:CTL: SyncSetKeyValue on ListPairedDevices0 [1634068362.130101][80880:80888] CHIP:CTL: SyncSetKeyValue on StartKeyID [1634068362.130170][80880:80888] CHIP:CTL: SyncSetKeyValue on PairedDevice65 Secure Session to Device Established Device temporary node id (**this does not match spec**): 101 [1634068362.130639][80880:80888] CHIP:DMG: ICR moving to [Uninitiali] chip-device-ctrl > zcl NetworkCommissioning AddThreadNetwork 101 0 0 operationalDataset=hex:0e080000000000000000000300000b35060004001fffe00208dead00beef00cafe0708fddead00beef0000051086dc5f00a2e0780b519a395807da9942030a4f70656e546872656164010232070410dd8d6d6eea12a21ad2e15225c929113d0c0402a0fff8 breadcrumb=0 timeoutMs=1000 [1634068363.691905][80880:80888] CHIP:DMG: ICR moving to [Initialize] [1634068363.692012][80880:80888] CHIP:DMG: ICR moving to [AddCommand] [1634068363.692085][80880:80888] CHIP:IN: Marking old secure session for device 0x0000000000000065 as expired [1634068363.692143][80880:80888] CHIP:CTL: OnConnectionExpired was called for unknown device, ignoring it. [1634068363.692203][80880:80888] CHIP:IN: New secure session created for device 0x0000000000000065, key 0!! [1634068363.692597][80880:80888] CHIP:IN: Secure message was encrypted: Msg ID 4 [1634068363.692655][80880:80888] CHIP:IN: Build encrypted message 0xffffa8ff1f50 to 0x0000000000000065 of type 8 and protocolId 1 on exchange 3530r with MessageCounter 4. [1634068363.692761][80880:80888] CHIP:IN: Sending encrypted msg 0xffffa8ff1f50 to 0x0000000000000065 at utc time: 10140464 msec [1634068363.692811][80880:80888] CHIP:IN: Sending msg on generic transport [1634068363.693035][80880:80888] CHIP:DMG: ICR moving to [ Sending] [1634068363.780108][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068363.784257][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068363.784862][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068363.877560][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068363.881898][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068363.882182][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068363.975121][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068363.979214][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068363.979471][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068363.984257][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068363.984512][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068364.121246][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068364.125272][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068364.125777][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068364.126061][80880:80888] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 3530i [1634068364.126211][80880:80888] CHIP:DMG: InvokeCommand = [1634068364.126276][80880:80888] CHIP:DMG: { [1634068364.126320][80880:80888] CHIP:DMG: CommandList = [1634068364.126382][80880:80888] CHIP:DMG: [ [1634068364.126439][80880:80888] CHIP:DMG: CommandDataElement = [1634068364.126510][80880:80888] CHIP:DMG: { [1634068364.126579][80880:80888] CHIP:DMG: CommandPath = [1634068364.126652][80880:80888] CHIP:DMG: { [1634068364.126729][80880:80888] CHIP:DMG: EndpointId = 0x0, [1634068364.126813][80880:80888] CHIP:DMG: ClusterId = 0x31, [1634068364.126892][80880:80888] CHIP:DMG: CommandId = 0x6, [1634068364.126965][80880:80888] CHIP:DMG: }, [1634068364.127049][80880:80888] CHIP:DMG: [1634068364.127114][80880:80888] CHIP:DMG: StatusElement = [1634068364.127189][80880:80888] CHIP:DMG: { [1634068364.127269][80880:80888] CHIP:DMG: GeneralCode = 0x0, [1634068364.127350][80880:80888] CHIP:DMG: ProtocolId = 0x1, [1634068364.127426][80880:80888] CHIP:DMG: protocolCode = 0x0, [1634068364.127498][80880:80888] CHIP:DMG: }, [1634068364.127580][80880:80888] CHIP:DMG: [1634068364.127650][80880:80888] CHIP:DMG: }, [1634068364.127727][80880:80888] CHIP:DMG: [1634068364.127782][80880:80888] CHIP:DMG: ], [1634068364.127900][80880:80888] CHIP:DMG: [1634068364.127957][80880:80888] CHIP:DMG: } SetCommandIndexStatus commandHandle=1 commandIndex=1 [1634068364.128606][80880:80888] CHIP:ZCL: DefaultResponse: [1634068364.128665][80880:80888] CHIP:ZCL: Transaction: 0xffffac75e390 [1634068364.128719][80880:80888] CHIP:ZCL: status: EMBER_ZCL_STATUS_SUCCESS (0x00) [1634068364.128770][80880:80888] CHIP:ZCL: IMDefaultResponseCallback: Missing success callback [1634068364.128817][80880:80888] CHIP:ZCL: IMDefaultResponseCallback: Missing failure callback [1634068364.128993][80880:80888] CHIP:DMG: ICR moving to [Uninitiali] Received command status response: Container: ProtocolId = 1 ProtocolCode = 0 EndpointId = 0 ClusterId = 49 CommandId = 6 CommandIndex = 1 chip-device-ctrl > [1634068366.610707][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068366.610956][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068366.704955][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 zcl NetworkCommissioning EnableNetwork 101 0 0 networkID=hex:dead00beef00cafe breadcrumb=0 timeoutMs=1000 [1634068368.388452][80880:80888] CHIP:DMG: ICR moving to [Initialize] [1634068368.388572][80880:80888] CHIP:DMG: ICR moving to [AddCommand] [1634068368.388808][80880:80888] CHIP:IN: Secure message was encrypted: Msg ID 5 [1634068368.389007][80880:80888] CHIP:IN: Build encrypted message 0xffffa8ff1f50 to 0x0000000000000065 of type 8 and protocolId 1 on exchange 3531r with MessageCounter 5. [1634068368.389096][80880:80888] CHIP:IN: Sending encrypted msg 0xffffa8ff1f50 to 0x0000000000000065 at utc time: 10145161 msec [1634068368.389174][80880:80888] CHIP:IN: Sending msg on generic transport [1634068368.389403][80880:80888] CHIP:DMG: ICR moving to [ Sending] [1634068368.460184][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068368.464053][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068368.464292][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068368.469127][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068368.469384][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068368.655166][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068368.659447][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068368.659716][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068368.665156][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068368.665423][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068368.850107][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1634068368.853891][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068368.854114][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068368.854362][80880:80888] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 3531i [1634068368.854507][80880:80888] CHIP:DMG: InvokeCommand = [1634068368.854563][80880:80888] CHIP:DMG: { [1634068368.854603][80880:80888] CHIP:DMG: CommandList = [1634068368.854675][80880:80888] CHIP:DMG: [ [1634068368.854725][80880:80888] CHIP:DMG: CommandDataElement = [1634068368.854791][80880:80888] CHIP:DMG: { [1634068368.854844][80880:80888] CHIP:DMG: CommandPath = [1634068368.854898][80880:80888] CHIP:DMG: { [1634068368.854971][80880:80888] CHIP:DMG: EndpointId = 0x0, [1634068368.855053][80880:80888] CHIP:DMG: ClusterId = 0x31, [1634068368.855130][80880:80888] CHIP:DMG: CommandId = 0xc, [1634068368.855203][80880:80888] CHIP:DMG: }, [1634068368.855284][80880:80888] CHIP:DMG: [1634068368.855337][80880:80888] CHIP:DMG: StatusElement = [1634068368.855410][80880:80888] CHIP:DMG: { [1634068368.855476][80880:80888] CHIP:DMG: GeneralCode = 0x0, [1634068368.855533][80880:80888] CHIP:DMG: ProtocolId = 0x1, [1634068368.855599][80880:80888] CHIP:DMG: protocolCode = 0x0, [1634068368.855664][80880:80888] CHIP:DMG: }, [1634068368.855718][80880:80888] CHIP:DMG: [1634068368.855772][80880:80888] CHIP:DMG: }, [1634068368.855889][80880:80888] CHIP:DMG: [1634068368.855936][80880:80888] CHIP:DMG: ], [1634068368.855996][80880:80888] CHIP:DMG: [1634068368.856039][80880:80888] CHIP:DMG: } SetCommandIndexStatus commandHandle=1 commandIndex=1 [1634068368.856943][80880:80888] CHIP:ZCL: DefaultResponse: [1634068368.856993][80880:80888] CHIP:ZCL: Transaction: 0xffffac75e390 [1634068368.857034][80880:80888] CHIP:ZCL: status: EMBER_ZCL_STATUS_SUCCESS (0x00) [1634068368.857079][80880:80888] CHIP:ZCL: IMDefaultResponseCallback: Missing success callback [1634068368.857119][80880:80888] CHIP:ZCL: IMDefaultResponseCallback: Missing failure callback [1634068368.857281][80880:80888] CHIP:DMG: ICR moving to [Uninitiali] Received command status response: Container: ProtocolId = 1 ProtocolCode = 0 EndpointId = 0 ClusterId = 49 CommandId = 12 CommandIndex = 1 chip-device-ctrl > [1634068371.291452][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068371.291924][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068371.433646][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 close-ble[1634068373.875225][80880:80884] CHIP:DL: Indication received, conn = 0xffffa0043580 [1634068373.875491][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1634068374.320798][80880:80888] CHIP:IN: Clearing BLE pending packets. [1634068374.320955][80880:80888] CHIP:BLE: Auto-closing end point's BLE connection. [1634068374.321056][80880:80888] CHIP:DL: Closing BLE GATT connection (con 0xffffa0043580) [1634068374.321348][80880:80884] CHIP:DL: BluezDisconnect peer=00:0D:6F:20:C0:D0 chip-device-ctrl > [1634068376.266532][80880:80888] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1634068376.266629][80880:80888] CHIP:BLE: no endpoint for unsub complete [1634068376.268805][80880:80884] CHIP:DL: Bluez disconnected [1634068376.268867][80880:80884] CHIP:DL: Bluez notify CHIPoBluez connection disconnected get-fabricid Get fabric ID complete Raw Fabric ID: 0x0000000000000000 (0) Compressed Fabric ID: 0x3056bb80a3b83b36 (3483177522994625334) chip-device-ctrl > resolve 3483177522994625334 101 [1634068385.220385][80880:80888] CHIP:DL: Avahi resolve found [1634068385.220577][80880:80888] CHIP:DIS: Node ID resolved for 0x0000000000000065 to [fd11:22::3c90:3bd:b13c:54c0]:5540 [1634068385.220727][80880:80888] CHIP:CTL: SyncSetKeyValue on PairedDevice65 Node address has been updated [1634068385.221047][80880:80888] CHIP:CTL: OperationalDiscoveryComplete for device ID 101 [1634068385.221382][80880:80888] CHIP:CTL: Enabling CASE session establishment for the device [1634068385.221503][80880:80888] CHIP:CTL: SyncSetKeyValue on PairedDevice65 [1634068385.221587][80880:80888] CHIP:IN: Marking old secure session for device 0x0000000000000065 as expired [1634068385.221735][80880:80888] CHIP:CTL: SyncSetKeyValue on PairedDevice65 [1634068385.221798][80880:80888] CHIP:CTL: SyncSetKeyValue on StartKeyID [1634068385.223173][80880:80888] CHIP:IN: Build plaintext message 0x12108ad8 to 0x0000000000000000 of type 48 and protocolId 0 on exchange 3532r with MessageCounter 28882131. [1634068385.223285][80880:80888] CHIP:IN: Sending plaintext msg 0x12108ad8 to 0x0000000000000000 at utc time: 10161995 msec [1634068385.223346][80880:80888] CHIP:IN: Sending msg on generic transport [1634068385.223742][80880:80888] CHIP:SC: Sent SigmaR1 msg [1634068385.681592][80880:80888] CHIP:EM: Received message of type 0x31 with vendorId 0x0000 and protocolId 0x0000 on exchange 3532i [1634068385.681755][80880:80888] CHIP:EM: Rxd Ack; Removing MessageCounter:01B8B4D3 from Retrans Table [1634068385.681814][80880:80888] CHIP:EM: Removed CHIP MessageCounter:01B8B4D3 from RetransTable [1634068385.681903][80880:80888] CHIP:SC: Received SigmaR2 msg [1634068385.681986][80880:80888] CHIP:SC: Peer assigned session key ID 1 [1634068385.689661][80880:80888] CHIP:SC: Sending SigmaR3 [1634068385.690506][80880:80888] CHIP:EM: Piggybacking Ack for MessageCounter:3129F646 on exchange: 3532i [1634068385.690619][80880:80888] CHIP:IN: Build plaintext message 0x12108ad8 to 0x0000000000000000 of type 50 and protocolId 0 on exchange 3532r with MessageCounter 28882132. [1634068385.690707][80880:80888] CHIP:IN: Sending plaintext msg 0x12108ad8 to 0x0000000000000000 at utc time: 10162462 msec [1634068385.690763][80880:80888] CHIP:IN: Sending msg on generic transport [1634068385.691045][80880:80888] CHIP:SC: Sent SigmaR3 msg [1634068385.691135][80880:80888] CHIP:IN: New secure session created for device 0x0000000000000065, key 1!! Commissioning complete Current address: fd11:22::3c90:3bd:b13c:54c0:5540 chip-device-ctrl > [1634068386.463607][80880:80888] CHIP:EM: Received message of type 0x10 with vendorId 0x0000 and protocolId 0x0000 on exchange 3532i [1634068386.463766][80880:80888] CHIP:EM: Rxd Ack; Removing MessageCounter:01B8B4D4 from Retrans Table [1634068386.463865][80880:80888] CHIP:EM: Removed CHIP MessageCounter:01B8B4D4 from RetransTable chip-device-ctrl > open-commissioning-window 101 -t 100 -o 1 -d 3840 -i 1000 [1634068402.594707][80880:80888] CHIP:CTL: OpenCommissioningWindow for device ID 101 [1634068402.599625][80880:80888] CHIP:DMG: ICR moving to [Initialize] [1634068402.599682][80880:80888] CHIP:DMG: ICR moving to [AddCommand] [1634068402.599857][80880:80888] CHIP:IN: Secure message was encrypted: Msg ID 0 [1634068402.599884][80880:80888] CHIP:IN: Build encrypted message 0x12108ad8 to 0x0000000000000065 of type 8 and protocolId 1 on exchange 3533r with MessageCounter 0. [1634068402.599923][80880:80888] CHIP:IN: Sending encrypted msg 0x12108ad8 to 0x0000000000000065 at utc time: 10179372 msec [1634068402.599947][80880:80888] CHIP:IN: Sending msg on generic transport [1634068402.600094][80880:80888] CHIP:DMG: ICR moving to [ Sending] [1634068402.600144][80880:80888] CHIP:CTL: Manual pairing code: [35196617942] [1634068402.600221][80880:80888] CHIP:CTL: SetupQRCode: [MT:000006DB00M3AQ0NN00] chip-device-ctrl > [1634068403.024568][80880:80888] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0001 on exchange 3533i [1634068403.024699][80880:80888] CHIP:EM: Rxd Ack; Removing MessageCounter:00000000 from Retrans Table [1634068403.024745][80880:80888] CHIP:EM: Removed CHIP MessageCounter:00000000 from RetransTable [1634068403.024833][80880:80888] CHIP:DMG: InvokeCommand = [1634068403.024884][80880:80888] CHIP:DMG: { [1634068403.024922][80880:80888] CHIP:DMG: CommandList = [1634068403.024966][80880:80888] CHIP:DMG: [ [1634068403.025048][80880:80888] CHIP:DMG: CommandDataElement = [1634068403.025109][80880:80888] CHIP:DMG: { [1634068403.025150][80880:80888] CHIP:DMG: CommandPath = [1634068403.025203][80880:80888] CHIP:DMG: { [1634068403.025271][80880:80888] CHIP:DMG: EndpointId = 0x0, [1634068403.025326][80880:80888] CHIP:DMG: ClusterId = 0x3c, [1634068403.025393][80880:80888] CHIP:DMG: CommandId = 0x0, [1634068403.025443][80880:80888] CHIP:DMG: }, [1634068403.025515][80880:80888] CHIP:DMG: [1634068403.025567][80880:80888] CHIP:DMG: StatusElement = [1634068403.025618][80880:80888] CHIP:DMG: { [1634068403.025682][80880:80888] CHIP:DMG: GeneralCode = 0x0, [1634068403.025737][80880:80888] CHIP:DMG: ProtocolId = 0x1, [1634068403.025807][80880:80888] CHIP:DMG: protocolCode = 0x0, [1634068403.025857][80880:80888] CHIP:DMG: }, [1634068403.025942][80880:80888] CHIP:DMG: [1634068403.026010][80880:80888] CHIP:DMG: }, [1634068403.026081][80880:80888] CHIP:DMG: [1634068403.026124][80880:80888] CHIP:DMG: ], [1634068403.026176][80880:80888] CHIP:DMG: [1634068403.026214][80880:80888] CHIP:DMG: } SetCommandIndexStatus commandHandle=1 commandIndex=1 [1634068403.026716][80880:80888] CHIP:ZCL: DefaultResponse: [1634068403.026759][80880:80888] CHIP:ZCL: Transaction: 0xffffac75e390 [1634068403.026795][80880:80888] CHIP:ZCL: status: EMBER_ZCL_STATUS_SUCCESS (0x00) [1634068403.026838][80880:80888] CHIP:CTL: Successfully opened pairing window on the device [1634068403.026945][80880:80888] CHIP:DMG: ICR moving to [Uninitiali] [1634068403.027002][80880:80888] CHIP:EM: Sending Standalone Ack for MessageCounter:00000001 [1634068403.027130][80880:80888] CHIP:IN: Secure message was encrypted: Msg ID 1 [1634068403.027175][80880:80888] CHIP:IN: Build encrypted message 0xffffa8ff2ad0 to 0x0000000000000065 of type 16 and protocolId 0 on exchange 3533r with MessageCounter 1. [1634068403.027236][80880:80888] CHIP:IN: Sending encrypted msg 0xffffa8ff2ad0 to 0x0000000000000065 at utc time: 10179799 msec [1634068403.027280][80880:80888] CHIP:IN: Sending msg on generic transport [1634068403.027486][80880:80888] CHIP:EM: Flushed pending ack for MessageCounter:00000001 chip-device-ctrl > setup-payload parse-manual 35196617942 Version: 0 VendorID: 0 ProductID: 0 CommissioningFlow: 0 RendezvousInformation: 0 Discriminator: 3840 SetUpPINCode: 29395710 chip-device-ctrl >