Regarding Commissioning a Nano leaf Matter bulb A60 over Thread

[Varun2103]

Hello everyone,

I'm trying to commission the Nano leaf Bulb A60 using chip-tool in my Linux machine and OTBR in docker which is also in my Linux machine.

I'm running docker using following commands

sudo modprobe ip6table_filter
sudo docker run -it --rm --privileged --name otbr --network otbr -p 8080:80 \
--sysctl "net.ipv6.conf.all.disable_ipv6=0 net.ipv4.conf.all.forwarding=1 net.ipv6.conf.all.forwarding=1" \
--volume /dev/ttyACM0:/dev/radio nrfconnect/otbr:9185bda --radio-url spinel+hdlc+uart:///dev/radio?uart-baudrate=1000000

and my docker is installed using following link https://openthread.io/guides/border-router/docker

and the image I'm using for OTBR  is nRFconnect/otbr:9185bda

and my dongle nRF52840 contains RCP application programmed using the following link https://developer.nordicsemi.com/nRF_Connect_SDK/doc/1.9.99-dev1/matter/openthread_rcp_nrf_dongle.html

and I'm using chip-tool from the following link https://github.com/nrfconnect/sdk-connectedhomeip/releases and the version is V 2.4.0 and the I downloaded chip-tool for linux x64.

After running the docker I formed thread network using OTBR-web page, and then I entered into docker using following command "docker exec -it otbr sh". After entering into the docker I started thread interface using following commands

ot-ctl ifconfig up

ot-ctl thread start

After this I can see the state of OTBR  as leader.

But when I opens the otbr-web and click on Join, I'm getting following error

And when I'm running the chip-tool using following command

./chip-tool pairing code-thread 0x5671 hex:<Operational dataset> payload --bypass-attestation-verifier true

I'm getting following error in chip-tool :

./chip-tool pairing code-thread 0x5430 hex:0e08000000000001000035060004001fffe00708fd35a26dac0e38170c0402a0f7f8030e4f70656e54687265616444656d6f0410445f2b5ca6f2a93a55ce570a70efeecb000300000f0208111111112222222201021234051000112233445566778899aabbccddeeff MT:CWBT0O.R026RLA61M00 --bypass-attestation-verifier true
[1688538650.836878][66408:66408] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1688538650.836944][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_kvs-uu3ozA)
[1688538650.836985][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs)
[1688538650.837061][66408:66408] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1688538650.837082][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-jdD00I)
[1688538650.837128][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1688538650.837140][66408:66408] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1688538650.837158][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_config.ini-9W41So)
[1688538650.837182][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1688538650.837208][66408:66408] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1688538650.837243][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-XTvSgU)
[1688538650.837263][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688538650.837297][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-YLXxbd)
[1688538650.837431][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1688538650.837439][66408:66408] CHIP:DL: NVS set: chip-factory/unique-id = "7385849150E95DB2"
[1688538650.837470][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-qNo7Zq)
[1688538650.879061][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1688538650.879136][66408:66408] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1)
[1688538650.879257][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-3731KJ)
[1688538650.879470][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1688538650.879490][66408:66408] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001)
[1688538650.879554][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-JWWW6k)
[1688538650.879681][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688538650.879698][66408:66408] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1)
[1688538650.879786][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-VOHVQy)
[1688538651.015065][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688538651.015127][66408:66408] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1688538651.015247][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-u8Kw84)
[1688538651.015478][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688538651.015504][66408:66408] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0)
[1688538651.015582][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_config.ini-FLeOTT)
[1688538651.015768][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1688538651.015786][66408:66408] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0)
[1688538651.015849][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_config.ini-vh1HrY)
[1688538651.016245][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1688538651.016267][66408:66408] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2)
[1688538651.016614][66408:66408] CHIP:DL: Got Ethernet interface: enp2s0
[1688538651.016792][66408:66408] CHIP:DL: Found the primary Ethernet interface:enp2s0
[1688538651.017029][66408:66408] CHIP:DL: Got WiFi interface: wlp3s0
[1688538651.017239][66408:66408] CHIP:DL: Found the primary WiFi interface:wlp3s0
[1688538651.017268][66408:66408] CHIP:IN: UDP::Init bind&listen port=0
[1688538651.017294][66408:66408] CHIP:IN: UDP::Init bound to port=56488
[1688538651.017301][66408:66408] CHIP:IN: UDP::Init bind&listen port=0
[1688538651.017321][66408:66408] CHIP:IN: UDP::Init bound to port=40472
[1688538651.017327][66408:66408] CHIP:IN: BLEBase::Init - setting/overriding transport
[1688538651.017332][66408:66408] CHIP:IN: TransportMgr initialized
[1688538651.017346][66408:66408] CHIP:FP: Initializing FabricTable from persistent storage
[1688538651.017362][66408:66408] CHIP:TS: Last Known Good Time: [unknown]
[1688538651.017370][66408:66408] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-06-01T07:38:45
[1688538651.106240][66408:66408] CHIP:ZCL: Using ZAP configuration...
[1688538651.109660][66408:66408] CHIP:DL: Avahi client registered
[1688538651.110410][66408:66408] CHIP:CTL: System State Initialized...
[1688538651.110474][66408:66408] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688538651.110495][66408:66408] CHIP:CTL: Setting attestation nonce to random value
[1688538651.110504][66408:66408] CHIP:CTL: Setting CSR nonce to random value
[1688538651.110673][66408:66410] CHIP:DL: CHIP task running
[1688538651.110755][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1688538651.110984][66408:66410] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688538651.111002][66408:66410] CHIP:CTL: Setting attestation nonce to random value
[1688538651.111009][66408:66410] CHIP:CTL: Setting CSR nonce to random value
[1688538651.111059][66408:66410] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1688538651.118197][66408:66410] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1688538651.248761][66408:66410] CHIP:CTL: Generating RCAC
[1688538651.256101][66408:66410] CHIP:CTL: Generating ICAC
[1688538651.261894][66408:66410] CHIP:CTL: Generating NOC
[1688538651.265710][66408:66410] CHIP:FP: Validating NOC chain
[1688538651.277109][66408:66410] CHIP:FP: NOC chain validation successful
[1688538651.277134][66408:66410] CHIP:FP: Added new fabric at index: 0x1
[1688538651.277136][66408:66410] CHIP:FP: Assigned compressed fabric ID: 0xA5C323195DA1338E, node ID: 0x000000000001B669
[1688538651.277147][66408:66410] CHIP:TS: Last Known Good Time: 2023-06-01T07:38:45
[1688538651.277150][66408:66410] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1688538651.277153][66408:66410] CHIP:TS: Retaining current Last Known Good Time
[1688538651.277568][66408:66410] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1688538651.277851][66408:66410] CHIP:TS: Committing Last Known Good Time to storage: 2023-06-01T07:38:45
[1688538651.278169][66408:66410] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: A5C323195DA1338E)
[1688538651.282395][66408:66410] CHIP:CTL: Setting thread operational dataset from parameters
[1688538651.282404][66408:66410] CHIP:CTL: Setting attestation nonce to random value
[1688538651.282409][66408:66410] CHIP:CTL: Setting CSR nonce to random value
[1688538651.282429][66408:66410] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688538651.282432][66408:66410] CHIP:CTL: Starting commissioning discovery over BLE
[1688538651.282439][66408:66410] CHIP:CTL: Starting commissioning discovery over DNS-SD
[1688538651.282694][66408:66410] CHIP:DL: Long dispatch time: 172 ms, for event type 2
[1688538651.283700][66408:66409] CHIP:DL: TRACE: Bus acquired for name C-0368
[1688538651.285027][66408:66410] CHIP:DL: PlatformBlueZInit init success
[1688538651.285765][66408:66409] CHIP:BLE: BLE removing known devices.
[1688538651.286004][66408:66409] CHIP:BLE: BLE initiating scan.
[1688538651.404013][66408:66410] CHIP:DL: Long dispatch time: 121 ms, for event type 2
[1688538651.404165][66408:66410] CHIP:DL: Avahi browse: cache new
[1688538651.404198][66408:66410] CHIP:DL: Avahi browse: cache new
[1688538651.404221][66408:66410] CHIP:DL: Avahi browse: cache exhausted
[1688538651.420923][66408:66409] CHIP:BLE: Device 7D:6C:85:6A:98:9F does not look like a CHIP device.
[1688538651.424471][66408:66409] CHIP:BLE: Device 58:29:8A:1A:AA:AF does not look like a CHIP device.
[1688538651.425256][66408:66409] CHIP:BLE: Device 2F:B9:1F:52:45:65 does not look like a CHIP device.
[1688538651.433938][66408:66409] CHIP:BLE: Device 27:6D:94:D5:05:E8 does not look like a CHIP device.
[1688538651.436772][66408:66409] CHIP:BLE: Device 00:3E:5E:D1:68:D4 does not look like a CHIP device.
[1688538651.440896][66408:66409] CHIP:BLE: Device 0B:AB:00:CF:55:77 does not look like a CHIP device.
[1688538651.452991][66408:66409] CHIP:BLE: Device 70:AC:08:67:4F:AD does not look like a CHIP device.
[1688538651.453275][66408:66409] CHIP:BLE: Device 01:14:F5:4F:79:4C does not look like a CHIP device.
[1688538651.457898][66408:66409] CHIP:BLE: New device scanned: F0:82:C0:02:B4:7C
[1688538651.457910][66408:66409] CHIP:BLE: Device discriminator match. Attempting to connect.
[1688538652.294414][66408:66410] CHIP:DL: Avahi browse: all for now
[1688538652.852846][66408:66409] CHIP:DL: ConnectDevice complete
[1688538654.792673][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service001b
[1688538654.792686][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792688][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service001b
[1688538654.792689][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792691][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service001b
[1688538654.792693][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792696][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0001
[1688538654.792697][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792699][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0001
[1688538654.792701][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792703][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0001
[1688538654.792704][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792706][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service000c
[1688538654.792708][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792710][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service000c
[1688538654.792711][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792713][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service000c
[1688538654.792716][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792718][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792720][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792723][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792725][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792728][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792730][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792732][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792734][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792736][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792738][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792740][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792742][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792745][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service001b
[1688538654.792747][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792748][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service001b
[1688538654.792750][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792756][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service001b
[1688538654.792757][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792760][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792762][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792764][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792766][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792769][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792771][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792774][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792776][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792778][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792780][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792783][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0022
[1688538654.792784][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792788][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0001
[1688538654.792790][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792792][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0001
[1688538654.792794][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792796][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0001
[1688538654.792798][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792801][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792803][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792806][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792808][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792812][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792813][66408:66409] CHIP:DL: Char1 /org/bluez/hci0/dev_F0_82_C0_02_B4_7C/service0011
[1688538654.792817][66408:66409] CHIP:DL: New BLE connection 0x7f1fcc068ff0, device F0:82:C0:02:B4:7C, path /org/bluez/hci0/dev_F0_82_C0_02_B4_7C
[1688538654.792879][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16385
[1688538654.792885][66408:66410] CHIP:CTL: Discovered device to be commissioned over BLE
[1688538654.792893][66408:66410] CHIP:CTL: Attempting PASE connection to BLE
[1688538654.792909][66408:66410] CHIP:IN: BleConnectionComplete: endPoint 0x5618de3c83c0
[1688538654.793044][66408:66410] CHIP:IN: SecureSession[0x7f1fc4007c60]: Allocated Type:1 LSID:15257
[1688538654.793053][66408:66410] CHIP:SC: Assigned local session key ID 15257
[1688538654.793079][66408:66410] CHIP:EM: <<< [E:53072i S:0 M:33670166] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[1688538654.793090][66408:66410] CHIP:IN: (U) Sending msg 33670166 to IP address 'BLE'
[1688538654.793096][66408:66410] CHIP:IN: Message appended to BLE send queue
[1688538654.793100][66408:66410] CHIP:SC: Sent PBKDF param request
[1688538654.793105][66408:66410] CHIP:CTL: Commission called for node ID 0x0000000000005430
[1688538655.055914][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538655.146759][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1688538655.146788][66408:66410] CHIP:BLE: subscribe complete, ep = 0x5618de3c83c0
[1688538655.146929][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538655.147030][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538655.147045][66408:66410] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4
[1688538655.147051][66408:66410] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244.
[1688538655.147055][66408:66410] CHIP:BLE: local and remote recv window size = 5
[1688538655.147334][66408:66410] CHIP:IN: BLE EndPoint 0x5618de3c83c0 Connection Complete
[1688538655.235921][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538655.238426][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538655.238514][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538655.238606][66408:66410] CHIP:EM: >>> [E:53072i S:0 M:64328130] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
[1688538655.238623][66408:66410] CHIP:EM: Found matching exchange: 53072i, Delegate: 0x7f1fc4017ce0
[1688538655.238640][66408:66410] CHIP:SC: Received PBKDF param response
[1688538655.238666][66408:66410] CHIP:SC: Peer assigned session ID 33688
[1688538655.238682][66408:66410] CHIP:SC: Found MRP parameters in the message
[1688538655.396524][66408:66410] CHIP:EM: <<< [E:53072i S:0 M:33670167] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
[1688538655.396544][66408:66410] CHIP:IN: (U) Sending msg 33670167 to IP address 'BLE'
[1688538655.396681][66408:66410] CHIP:SC: Sent spake2p msg1
[1688538655.396768][66408:66410] CHIP:DL: Long dispatch time: 158 ms, for event type 16389
[1688538655.460812][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538657.297955][66408:66410] CHIP:DL: Re-trying resolve
[1688538657.299211][66408:66410] CHIP:DL: Re-trying resolve
[1688538659.548929][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538659.549084][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538659.549175][66408:66410] CHIP:EM: >>> [E:53072i S:0 M:64328131] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
[1688538659.549196][66408:66410] CHIP:EM: Found matching exchange: 53072i, Delegate: 0x7f1fc4017ce0
[1688538659.549214][66408:66410] CHIP:SC: Received spake2p msg2
[1688538659.572845][66408:66410] CHIP:EM: <<< [E:53072i S:0 M:33670168] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
[1688538659.572866][66408:66410] CHIP:IN: (U) Sending msg 33670168 to IP address 'BLE'
[1688538659.573004][66408:66410] CHIP:SC: Sent spake2p msg3
[1688538659.646133][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538659.646272][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538659.646375][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538659.646516][66408:66410] CHIP:EM: >>> [E:53072i S:0 M:64328132] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1688538659.646540][66408:66410] CHIP:EM: Found matching exchange: 53072i, Delegate: 0x7f1fc4017ce0
[1688538659.646602][66408:66410] CHIP:SC: SecureSession[0x7f1fc4007c60]: Moving from state 'kEstablishing' --> 'kActive'
[1688538659.646611][66408:66410] CHIP:IN: SecureSession[0x7f1fc4007c60]: Activated - Type:1 LSID:15257
[1688538659.646618][66408:66410] CHIP:IN: New secure session activated for device <FFFFFFFB00000000, 0>, LSID:15257 PSID:33688!
[1688538659.646632][66408:66410] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1688538659.646642][66408:66410] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688538659.646653][66408:66410] CHIP:TOO: Pairing Success
[1688538659.646659][66408:66410] CHIP:TOO: PASE establishment successful
[1688538659.646672][66408:66410] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1688538659.646683][66408:66410] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo'
[1688538659.646692][66408:66410] CHIP:CTL: Sending request for commissioning information
[1688538659.646714][66408:66410] CHIP:DMG: SendReadRequest ReadClient[0x7f1fc4019f30]: Sending Read Request
[1688538659.646799][66408:66410] CHIP:EM: <<< [E:53073i S:15257 M:213358141] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
[1688538659.646816][66408:66410] CHIP:IN: (S) Sending msg 213358141 on secure session with LSID: 15257
[1688538659.647113][66408:66410] CHIP:DMG: MoveToState ReadClient[0x7f1fc4019f30]: Moving to [AwaitingIn]
[1688538659.735766][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538659.738935][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538659.739006][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538659.826381][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538659.826512][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538659.826597][66408:66410] CHIP:EM: >>> [E:53073i S:15257 M:171851819] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
[1688538659.826612][66408:66410] CHIP:EM: Found matching exchange: 53073i, Delegate: 0x7f1fc4019f40
[1688538659.826664][66408:66410] CHIP:DMG: ReportDataMessage =
[1688538659.826673][66408:66410] CHIP:DMG: {
[1688538659.826680][66408:66410] CHIP:DMG: 	AttributeReportIBs =
[1688538659.826694][66408:66410] CHIP:DMG: 	[
[1688538659.826704][66408:66410] CHIP:DMG: 		AttributeReportIB =
[1688538659.826717][66408:66410] CHIP:DMG: 		{
[1688538659.826723][66408:66410] CHIP:DMG: 			AttributeDataIB =
[1688538659.826729][66408:66410] CHIP:DMG: 			{
[1688538659.826742][66408:66410] CHIP:DMG: 				DataVersion = 0xc9bfbd7,
[1688538659.826750][66408:66410] CHIP:DMG: 				AttributePathIB =
[1688538659.826762][66408:66410] CHIP:DMG: 				{
[1688538659.826773][66408:66410] CHIP:DMG: 					Endpoint = 0x0,
[1688538659.826782][66408:66410] CHIP:DMG: 					Cluster = 0x31,
[1688538659.826795][66408:66410] CHIP:DMG: 					Attribute = 0x0000_0003,
[1688538659.826803][66408:66410] CHIP:DMG: 				}
[1688538659.826811][66408:66410] CHIP:DMG: 					
[1688538659.826819][66408:66410] CHIP:DMG: 				Data = 20, 
[1688538659.826826][66408:66410] CHIP:DMG: 			},
[1688538659.826835][66408:66410] CHIP:DMG: 			
[1688538659.826840][66408:66410] CHIP:DMG: 		},
[1688538659.826853][66408:66410] CHIP:DMG: 		
[1688538659.826858][66408:66410] CHIP:DMG: 		AttributeReportIB =
[1688538659.826867][66408:66410] CHIP:DMG: 		{
[1688538659.826873][66408:66410] CHIP:DMG: 			AttributeDataIB =
[1688538659.826885][66408:66410] CHIP:DMG: 			{
[1688538659.826895][66408:66410] CHIP:DMG: 				DataVersion = 0xbac92693,
[1688538659.826905][66408:66410] CHIP:DMG: 				AttributePathIB =
[1688538659.826916][66408:66410] CHIP:DMG: 				{
[1688538659.826926][66408:66410] CHIP:DMG: 					Endpoint = 0x0,
[1688538659.826936][66408:66410] CHIP:DMG: 					Cluster = 0x28,
[1688538659.826947][66408:66410] CHIP:DMG: 					Attribute = 0x0000_0004,
[1688538659.826968][66408:66410] CHIP:DMG: 				}
[1688538659.826981][66408:66410] CHIP:DMG: 					
[1688538659.826992][66408:66410] CHIP:DMG: 				Data = 67, 
[1688538659.827001][66408:66410] CHIP:DMG: 			},
[1688538659.827014][66408:66410] CHIP:DMG: 			
[1688538659.827021][66408:66410] CHIP:DMG: 		},
[1688538659.827038][66408:66410] CHIP:DMG: 		
[1688538659.827045][66408:66410] CHIP:DMG: 		AttributeReportIB =
[1688538659.827059][66408:66410] CHIP:DMG: 		{
[1688538659.827067][66408:66410] CHIP:DMG: 			AttributeDataIB =
[1688538659.827077][66408:66410] CHIP:DMG: 			{
[1688538659.827086][66408:66410] CHIP:DMG: 				DataVersion = 0xbac92693,
[1688538659.827095][66408:66410] CHIP:DMG: 				AttributePathIB =
[1688538659.827105][66408:66410] CHIP:DMG: 				{
[1688538659.827116][66408:66410] CHIP:DMG: 					Endpoint = 0x0,
[1688538659.827126][66408:66410] CHIP:DMG: 					Cluster = 0x28,
[1688538659.827136][66408:66410] CHIP:DMG: 					Attribute = 0x0000_0002,
[1688538659.827145][66408:66410] CHIP:DMG: 				}
[1688538659.827158][66408:66410] CHIP:DMG: 					
[1688538659.827167][66408:66410] CHIP:DMG: 				Data = 4442, 
[1688538659.827176][66408:66410] CHIP:DMG: 			},
[1688538659.827209][66408:66410] CHIP:DMG: 			
[1688538659.827216][66408:66410] CHIP:DMG: 		},
[1688538659.827233][66408:66410] CHIP:DMG: 		
[1688538659.827239][66408:66410] CHIP:DMG: 		AttributeReportIB =
[1688538659.827253][66408:66410] CHIP:DMG: 		{
[1688538659.827260][66408:66410] CHIP:DMG: 			AttributeDataIB =
[1688538659.827271][66408:66410] CHIP:DMG: 			{
[1688538659.827280][66408:66410] CHIP:DMG: 				DataVersion = 0xc90c7f40,
[1688538659.827289][66408:66410] CHIP:DMG: 				AttributePathIB =
[1688538659.827299][66408:66410] CHIP:DMG: 				{
[1688538659.827309][66408:66410] CHIP:DMG: 					Endpoint = 0x0,
[1688538659.827320][66408:66410] CHIP:DMG: 					Cluster = 0x30,
[1688538659.827330][66408:66410] CHIP:DMG: 					Attribute = 0x0000_0003,
[1688538659.827340][66408:66410] CHIP:DMG: 				}
[1688538659.827352][66408:66410] CHIP:DMG: 					
[1688538659.827362][66408:66410] CHIP:DMG: 				Data = 0, 
[1688538659.827372][66408:66410] CHIP:DMG: 			},
[1688538659.827385][66408:66410] CHIP:DMG: 			
[1688538659.827392][66408:66410] CHIP:DMG: 		},
[1688538659.827410][66408:66410] CHIP:DMG: 		
[1688538659.827416][66408:66410] CHIP:DMG: 		AttributeReportIB =
[1688538659.827431][66408:66410] CHIP:DMG: 		{
[1688538659.827438][66408:66410] CHIP:DMG: 			AttributeDataIB =
[1688538659.827447][66408:66410] CHIP:DMG: 			{
[1688538659.827457][66408:66410] CHIP:DMG: 				DataVersion = 0xc90c7f40,
[1688538659.827465][66408:66410] CHIP:DMG: 				AttributePathIB =
[1688538659.827475][66408:66410] CHIP:DMG: 				{
[1688538659.827485][66408:66410] CHIP:DMG: 					Endpoint = 0x0,
[1688538659.827495][66408:66410] CHIP:DMG: 					Cluster = 0x30,
[1688538659.827506][66408:66410] CHIP:DMG: 					Attribute = 0x0000_0002,
[1688538659.827517][66408:66410] CHIP:DMG: 				}
[1688538659.827531][66408:66410] CHIP:DMG: 					
[1688538659.827541][66408:66410] CHIP:DMG: 				Data = 0, 
[1688538659.827550][66408:66410] CHIP:DMG: 			},
[1688538659.827564][66408:66410] CHIP:DMG: 			
[1688538659.827572][66408:66410] CHIP:DMG: 		},
[1688538659.827591][66408:66410] CHIP:DMG: 		
[1688538659.827597][66408:66410] CHIP:DMG: 		AttributeReportIB =
[1688538659.827613][66408:66410] CHIP:DMG: 		{
[1688538659.827620][66408:66410] CHIP:DMG: 			AttributeDataIB =
[1688538659.827630][66408:66410] CHIP:DMG: 			{
[1688538659.827639][66408:66410] CHIP:DMG: 				DataVersion = 0xc90c7f40,
[1688538659.827648][66408:66410] CHIP:DMG: 				AttributePathIB =
[1688538659.827659][66408:66410] CHIP:DMG: 				{
[1688538659.827668][66408:66410] CHIP:DMG: 					Endpoint = 0x0,
[1688538659.827678][66408:66410] CHIP:DMG: 					Cluster = 0x30,
[1688538659.827688][66408:66410] CHIP:DMG: 					Attribute = 0x0000_0001,
[1688538659.827700][66408:66410] CHIP:DMG: 				}
[1688538659.827712][66408:66410] CHIP:DMG: 					
[1688538659.827719][66408:66410] CHIP:DMG: 				Data = 
[1688538659.827728][66408:66410] CHIP:DMG: 				{
[1688538659.827739][66408:66410] CHIP:DMG: 					0x0 = 60, 
[1688538659.827762][66408:66410] CHIP:DMG: 					0x1 = 900, 
[1688538659.827769][66408:66410] CHIP:DMG: 				},
[1688538659.827775][66408:66410] CHIP:DMG: 			},
[1688538659.827785][66408:66410] CHIP:DMG: 			
[1688538659.827791][66408:66410] CHIP:DMG: 		},
[1688538659.827812][66408:66410] CHIP:DMG: 		
[1688538659.827819][66408:66410] CHIP:DMG: 		AttributeReportIB =
[1688538659.827833][66408:66410] CHIP:DMG: 		{
[1688538659.827839][66408:66410] CHIP:DMG: 			AttributeDataIB =
[1688538659.827849][66408:66410] CHIP:DMG: 			{
[1688538659.827858][66408:66410] CHIP:DMG: 				DataVersion = 0xc90c7f40,
[1688538659.827868][66408:66410] CHIP:DMG: 				AttributePathIB =
[1688538659.827879][66408:66410] CHIP:DMG: 				{
[1688538659.827890][66408:66410] CHIP:DMG: 					Endpoint = 0x0,
[1688538659.827901][66408:66410] CHIP:DMG: 					Cluster = 0x30,
[1688538659.827913][66408:66410] CHIP:DMG: 					Attribute = 0x0000_0000,
[1688538659.827923][66408:66410] CHIP:DMG: 				}
[1688538659.827935][66408:66410] CHIP:DMG: 					
[1688538659.827945][66408:66410] CHIP:DMG: 				Data = 0, 
[1688538659.827954][66408:66410] CHIP:DMG: 			},
[1688538659.827968][66408:66410] CHIP:DMG: 			
[1688538659.827975][66408:66410] CHIP:DMG: 		},
[1688538659.827992][66408:66410] CHIP:DMG: 		
[1688538659.827999][66408:66410] CHIP:DMG: 		AttributeReportIB =
[1688538659.828010][66408:66410] CHIP:DMG: 		{
[1688538659.828018][66408:66410] CHIP:DMG: 			AttributeDataIB =
[1688538659.828026][66408:66410] CHIP:DMG: 			{
[1688538659.828032][66408:66410] CHIP:DMG: 				DataVersion = 0xc9bfbd7,
[1688538659.828039][66408:66410] CHIP:DMG: 				AttributePathIB =
[1688538659.828045][66408:66410] CHIP:DMG: 				{
[1688538659.828052][66408:66410] CHIP:DMG: 					Endpoint = 0x0,
[1688538659.828060][66408:66410] CHIP:DMG: 					Cluster = 0x31,
[1688538659.828073][66408:66410] CHIP:DMG: 					Attribute = 0x0000_FFFC,
[1688538659.828083][66408:66410] CHIP:DMG: 				}
[1688538659.828095][66408:66410] CHIP:DMG: 					
[1688538659.828105][66408:66410] CHIP:DMG: 				Data = 2, 
[1688538659.828115][66408:66410] CHIP:DMG: 			},
[1688538659.828128][66408:66410] CHIP:DMG: 			
[1688538659.828136][66408:66410] CHIP:DMG: 		},
[1688538659.828149][66408:66410] CHIP:DMG: 		
[1688538659.828155][66408:66410] CHIP:DMG: 	],
[1688538659.828190][66408:66410] CHIP:DMG: 	
[1688538659.828196][66408:66410] CHIP:DMG: 	SuppressResponse = true, 
[1688538659.828202][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538659.828207][66408:66410] CHIP:DMG: }
[1688538659.828623][66408:66410] CHIP:CTL: ----- NetworkCommissioning Features: has Thread. endpointid = 0
[1688538659.828657][66408:66410] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo'
[1688538659.828667][66408:66410] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe'
[1688538659.828676][66408:66410] CHIP:CTL: Performing next commissioning step 'ArmFailSafe'
[1688538659.828683][66408:66410] CHIP:CTL: Arming failsafe (60 seconds)
[1688538659.828715][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538659.828733][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538659.828770][66408:66410] CHIP:EM: <<< [E:53074i S:15257 M:213358142] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538659.828784][66408:66410] CHIP:IN: (S) Sending msg 213358142 on secure session with LSID: 15257
[1688538659.829057][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538659.915979][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538659.917115][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538659.917223][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538659.917317][66408:66410] CHIP:EM: >>> [E:53074i S:15257 M:171851820] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538659.917333][66408:66410] CHIP:EM: Found matching exchange: 53074i, Delegate: 0x7f1fcc06a888
[1688538659.917349][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538659.917378][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538659.917386][66408:66410] CHIP:DMG: {
[1688538659.917395][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538659.917405][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538659.917423][66408:66410] CHIP:DMG: 	[
[1688538659.917433][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538659.917450][66408:66410] CHIP:DMG: 		{
[1688538659.917457][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538659.917469][66408:66410] CHIP:DMG: 			{
[1688538659.917478][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538659.917491][66408:66410] CHIP:DMG: 				{
[1688538659.917504][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538659.917516][66408:66410] CHIP:DMG: 					ClusterId = 0x30,
[1688538659.917530][66408:66410] CHIP:DMG: 					CommandId = 0x1,
[1688538659.917537][66408:66410] CHIP:DMG: 				},
[1688538659.917551][66408:66410] CHIP:DMG: 				
[1688538659.917559][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538659.917565][66408:66410] CHIP:DMG: 				{
[1688538659.917574][66408:66410] CHIP:DMG: 					0x0 = 0, 
[1688538659.917584][66408:66410] CHIP:DMG: 					0x1 = "" (0 chars), 
[1688538659.917592][66408:66410] CHIP:DMG: 				},
[1688538659.917599][66408:66410] CHIP:DMG: 			},
[1688538659.917614][66408:66410] CHIP:DMG: 			
[1688538659.917622][66408:66410] CHIP:DMG: 		},
[1688538659.917638][66408:66410] CHIP:DMG: 		
[1688538659.917646][66408:66410] CHIP:DMG: 	],
[1688538659.917671][66408:66410] CHIP:DMG: 	
[1688538659.917679][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538659.917687][66408:66410] CHIP:DMG: },
[1688538659.917722][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1688538659.917740][66408:66410] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1688538659.917754][66408:66410] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe'
[1688538659.917762][66408:66410] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1688538659.917776][66408:66410] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory'
[1688538659.917784][66408:66410] CHIP:CTL: Setting Regulatory Config
[1688538659.917791][66408:66410] CHIP:CTL: Device does not support configurable regulatory location
[1688538659.917825][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538659.917851][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538659.917890][66408:66410] CHIP:EM: <<< [E:53075i S:15257 M:213358143] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538659.917906][66408:66410] CHIP:IN: (S) Sending msg 213358143 on secure session with LSID: 15257
[1688538659.918147][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538659.918193][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538660.005763][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538660.006989][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.007061][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.007169][66408:66410] CHIP:EM: >>> [E:53075i S:15257 M:171851821] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538660.007186][66408:66410] CHIP:EM: Found matching exchange: 53075i, Delegate: 0x7f1fc4008b28
[1688538660.007199][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538660.007222][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538660.007228][66408:66410] CHIP:DMG: {
[1688538660.007234][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538660.007239][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538660.007250][66408:66410] CHIP:DMG: 	[
[1688538660.007256][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538660.007266][66408:66410] CHIP:DMG: 		{
[1688538660.007273][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538660.007282][66408:66410] CHIP:DMG: 			{
[1688538660.007289][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538660.007304][66408:66410] CHIP:DMG: 				{
[1688538660.007313][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538660.007322][66408:66410] CHIP:DMG: 					ClusterId = 0x30,
[1688538660.007330][66408:66410] CHIP:DMG: 					CommandId = 0x3,
[1688538660.007336][66408:66410] CHIP:DMG: 				},
[1688538660.007343][66408:66410] CHIP:DMG: 				
[1688538660.007351][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538660.007360][66408:66410] CHIP:DMG: 				{
[1688538660.007371][66408:66410] CHIP:DMG: 					0x0 = 0, 
[1688538660.007383][66408:66410] CHIP:DMG: 					0x1 = "" (0 chars), 
[1688538660.007395][66408:66410] CHIP:DMG: 				},
[1688538660.007406][66408:66410] CHIP:DMG: 			},
[1688538660.007420][66408:66410] CHIP:DMG: 			
[1688538660.007429][66408:66410] CHIP:DMG: 		},
[1688538660.007445][66408:66410] CHIP:DMG: 		
[1688538660.007454][66408:66410] CHIP:DMG: 	],
[1688538660.007471][66408:66410] CHIP:DMG: 	
[1688538660.007481][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538660.007490][66408:66410] CHIP:DMG: },
[1688538660.007534][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1688538660.007566][66408:66410] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0
[1688538660.007578][66408:66410] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory'
[1688538660.007585][66408:66410] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
[1688538660.007596][66408:66410] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest'
[1688538660.007603][66408:66410] CHIP:CTL: Sending request for PAI certificate
[1688538660.007608][66408:66410] CHIP:CTL: Sending Certificate Chain request to 0x7f1fc4017c90 device
[1688538660.007639][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538660.007657][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538660.007697][66408:66410] CHIP:EM: <<< [E:53076i S:15257 M:213358144] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538660.007712][66408:66410] CHIP:IN: (S) Sending msg 213358144 on secure session with LSID: 15257
[1688538660.007907][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538660.007942][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538660.096009][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538660.144197][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.144272][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.234487][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.234599][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.322513][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.322607][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.322715][66408:66410] CHIP:EM: >>> [E:53076i S:15257 M:171851822] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538660.322736][66408:66410] CHIP:EM: Found matching exchange: 53076i, Delegate: 0x7f1fcc06a888
[1688538660.322761][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538660.322792][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538660.322801][66408:66410] CHIP:DMG: {
[1688538660.322810][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538660.322818][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538660.322835][66408:66410] CHIP:DMG: 	[
[1688538660.322843][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538660.322862][66408:66410] CHIP:DMG: 		{
[1688538660.322871][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538660.322882][66408:66410] CHIP:DMG: 			{
[1688538660.322892][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538660.322903][66408:66410] CHIP:DMG: 				{
[1688538660.322912][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538660.322922][66408:66410] CHIP:DMG: 					ClusterId = 0x3e,
[1688538660.322932][66408:66410] CHIP:DMG: 					CommandId = 0x3,
[1688538660.322940][66408:66410] CHIP:DMG: 				},
[1688538660.322972][66408:66410] CHIP:DMG: 				
[1688538660.322982][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538660.322992][66408:66410] CHIP:DMG: 				{
[1688538660.323003][66408:66410] CHIP:DMG: 					0x0 = [
[1688538660.323105][66408:66410] CHIP:DMG: 							0x30, 0x82, 0x01, 0xda, 0x30, 0x82, 0x01, 0x80, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x14, 0x5a, 0xc0, 0x4b, 0x89, 0x16, 0xd6, 0xdb, 0xa7, 0x00, 0xba, 0xd6, 0x5f, 0x42, 0xf5, 0x2b, 0x0a, 0x27, 0xc6, 0x07, 0x99, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x36, 0x31, 0x20, 0x30, 0x1e, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x17, 0x53, 0x74, 0x72, 0x6f, 0x6e, 0x67, 0x4b, 0x65, 0x79, 0x20, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x47, 0x31, 0x20, 0x50, 0x41, 0x41, 0x31, 0x12, 0x30, 0x10, 0x06, 0x03, 0x55, 0x04, 0x0a, 0x0c, 0x09, 0x53, 0x74, 0x72, 0x6f, 0x6e, 0x67, 0x4b, 0x65, 0x79, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x39, 0x31, 0x34, 0x32, 0x32, 0x32, 0x36, 0x32, 0x38, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3a, 0x31, 0x22, 0x30, 0x20, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x19, 0x4e, 0x61, 0x6e, 0x6f, 0x6c, 0x65, 0x61, 0x66, 0x20, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x47, 0x31, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x32, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x31, 0x31, 0x35, 0x41, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0xd5, 0x30, 0x2a, 0x60, 0x9d, 0x71, 0x03, 0x26, 0xe7, 0x0c, 0x42, 0x85, 0x19, 0x8e, 0xba, 0xed, 0x0e, 0x88, 0x46, 0x6b, 0xb3, 0x23, 0xbb, 0x23, 0xde, 0x24, 0xd2, 0xf1, 0x48, 0x49, 0x45, 0x1e, 0xd0, 0xd4, 0xbb, 0xc7, 0xae, 0x12, 0xba, 0xa8, 0xc3, 0x74, 0xd9, 0xff, 0x5d, 0x4f, 0xc9, 0x58, 0x7e, 0x0f, 0xa9, 0x88, 0x4a, 0x6d, 0xbe, 0x8f, 0xa7, 0x12, 0x13, 0x
[1688538660.323152][66408:66410] CHIP:DMG: 					] (478 bytes)
[1688538660.323171][66408:66410] CHIP:DMG: 				},
[1688538660.323181][66408:66410] CHIP:DMG: 			},
[1688538660.323197][66408:66410] CHIP:DMG: 			
[1688538660.323205][66408:66410] CHIP:DMG: 		},
[1688538660.323220][66408:66410] CHIP:DMG: 		
[1688538660.323230][66408:66410] CHIP:DMG: 	],
[1688538660.323247][66408:66410] CHIP:DMG: 	
[1688538660.323256][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538660.323266][66408:66410] CHIP:DMG: },
[1688538660.323316][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1688538660.323336][66408:66410] CHIP:CTL: Received certificate chain from the device
[1688538660.323351][66408:66410] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest'
[1688538660.323365][66408:66410] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1688538660.323379][66408:66410] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest'
[1688538660.323388][66408:66410] CHIP:CTL: Sending request for DAC certificate
[1688538660.323395][66408:66410] CHIP:CTL: Sending Certificate Chain request to 0x7f1fc4017c90 device
[1688538660.323434][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538660.323448][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538660.323505][66408:66410] CHIP:EM: <<< [E:53077i S:15257 M:213358145] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538660.323525][66408:66410] CHIP:IN: (S) Sending msg 213358145 on secure session with LSID: 15257
[1688538660.323754][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538660.323789][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538660.410239][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538660.413380][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.413424][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.503527][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.503593][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.591753][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.591800][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.591848][66408:66410] CHIP:EM: >>> [E:53077i S:15257 M:171851823] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538660.591855][66408:66410] CHIP:EM: Found matching exchange: 53077i, Delegate: 0x7f1fcc06ab98
[1688538660.591862][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538660.591872][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538660.591874][66408:66410] CHIP:DMG: {
[1688538660.591876][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538660.591878][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538660.591882][66408:66410] CHIP:DMG: 	[
[1688538660.591883][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538660.591887][66408:66410] CHIP:DMG: 		{
[1688538660.591889][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538660.591892][66408:66410] CHIP:DMG: 			{
[1688538660.591894][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538660.591898][66408:66410] CHIP:DMG: 				{
[1688538660.591902][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538660.591907][66408:66410] CHIP:DMG: 					ClusterId = 0x3e,
[1688538660.591911][66408:66410] CHIP:DMG: 					CommandId = 0x3,
[1688538660.591915][66408:66410] CHIP:DMG: 				},
[1688538660.591919][66408:66410] CHIP:DMG: 				
[1688538660.591923][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538660.591926][66408:66410] CHIP:DMG: 				{
[1688538660.591929][66408:66410] CHIP:DMG: 					0x0 = [
[1688538660.591950][66408:66410] CHIP:DMG: 							0x30, 0x82, 0x01, 0xec, 0x30, 0x82, 0x01, 0x93, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x14, 0x1c, 0x3c, 0x4a, 0xfb, 0xc0, 0x59, 0x26, 0xed, 0x73, 0xb9, 0x11, 0x3f, 0xe5, 0x6c, 0xa7, 0xb0, 0xdf, 0x70, 0x03, 0xf3, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x3a, 0x31, 0x22, 0x30, 0x20, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x19, 0x4e, 0x61, 0x6e, 0x6f, 0x6c, 0x65, 0x61, 0x66, 0x20, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x47, 0x31, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x32, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x31, 0x31, 0x35, 0x41, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x33, 0x30, 0x33, 0x30, 0x37, 0x30, 0x35, 0x31, 0x38, 0x32, 0x33, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x4f, 0x31, 0x21, 0x30, 0x1f, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x18, 0x4e, 0x61, 0x6e, 0x6f, 0x6c, 0x65, 0x61, 0x66, 0x20, 0x44, 0x41, 0x43, 0x20, 0x4e, 0x32, 0x33, 0x31, 0x30, 0x30, 0x42, 0x41, 0x59, 0x33, 0x36, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x31, 0x31, 0x35, 0x41, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x02, 0x0c, 0x04, 0x30, 0x30, 0x34, 0x33, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x6f, 0x73, 0xe5, 0x57, 0x07, 0x76, 0xe9, 0x76, 0xec, 0xec, 0x1b, 0xf9, 0x4e, 0x87, 0x2b, 0x32, 0x3e, 0x7a, 0x09, 0x03, 0x72, 0x32, 0x67, 0x4b, 0xb6, 0x1b, 0xf9, 0xb2, 0x2f, 0x6e, 0xd7, 0x3c, 0x0f, 0x30, 0x
[1688538660.591961][66408:66410] CHIP:DMG: 					] (496 bytes)
[1688538660.591966][66408:66410] CHIP:DMG: 				},
[1688538660.591969][66408:66410] CHIP:DMG: 			},
[1688538660.591974][66408:66410] CHIP:DMG: 			
[1688538660.591977][66408:66410] CHIP:DMG: 		},
[1688538660.591982][66408:66410] CHIP:DMG: 		
[1688538660.591985][66408:66410] CHIP:DMG: 	],
[1688538660.591991][66408:66410] CHIP:DMG: 	
[1688538660.591994][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538660.591997][66408:66410] CHIP:DMG: },
[1688538660.592011][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1688538660.592018][66408:66410] CHIP:CTL: Received certificate chain from the device
[1688538660.592025][66408:66410] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest'
[1688538660.592030][66408:66410] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1688538660.592036][66408:66410] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest'
[1688538660.592038][66408:66410] CHIP:CTL: Sending Attestation Request to the device.
[1688538660.592042][66408:66410] CHIP:CTL: Sending Attestation request to 0x7f1fc4017c90 device
[1688538660.592057][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538660.592061][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538660.592076][66408:66410] CHIP:EM: <<< [E:53078i S:15257 M:213358146] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538660.592082][66408:66410] CHIP:IN: (S) Sending msg 213358146 on secure session with LSID: 15257
[1688538660.592174][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538660.592180][66408:66410] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information
[1688538660.592190][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538660.680397][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538660.683411][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.683446][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.772079][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.772125][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.772172][66408:66410] CHIP:EM: >>> [E:53078i S:15257 M:171851824] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538660.772179][66408:66410] CHIP:EM: Found matching exchange: 53078i, Delegate: 0x7f1fcc06ae58
[1688538660.772189][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538660.772200][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538660.772204][66408:66410] CHIP:DMG: {
[1688538660.772208][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538660.772210][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538660.772214][66408:66410] CHIP:DMG: 	[
[1688538660.772216][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538660.772221][66408:66410] CHIP:DMG: 		{
[1688538660.772223][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538660.772226][66408:66410] CHIP:DMG: 			{
[1688538660.772228][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538660.772234][66408:66410] CHIP:DMG: 				{
[1688538660.772238][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538660.772241][66408:66410] CHIP:DMG: 					ClusterId = 0x3e,
[1688538660.772243][66408:66410] CHIP:DMG: 					CommandId = 0x1,
[1688538660.772246][66408:66410] CHIP:DMG: 				},
[1688538660.772249][66408:66410] CHIP:DMG: 				
[1688538660.772252][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538660.772255][66408:66410] CHIP:DMG: 				{
[1688538660.772261][66408:66410] CHIP:DMG: 					0x0 = [
[1688538660.772283][66408:66410] CHIP:DMG: 							0x15, 0x30, 0x01, 0xea, 0x30, 0x81, 0xe7, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x81, 0xd9, 0x30, 0x81, 0xd6, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x43, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x36, 0x04, 0x34, 0x15, 0x24, 0x00, 0x01, 0x25, 0x01, 0x5a, 0x11, 0x36, 0x02, 0x04, 0x43, 0x18, 0x25, 0x03, 0x0d, 0x01, 0x2c, 0x04, 0x13, 0x43, 0x53, 0x41, 0x32, 0x32, 0x30, 0x39, 0x39, 0x4d, 0x41, 0x54, 0x34, 0x30, 0x30, 0x39, 0x39, 0x2d, 0x32, 0x34, 0x24, 0x05, 0x00, 0x24, 0x06, 0x00, 0x24, 0x07, 0x00, 0x24, 0x08, 0x02, 0x18, 0x31, 0x7d, 0x30, 0x7b, 0x02, 0x01, 0x03, 0x80, 0x14, 0xfe, 0x34, 0x3f, 0x95, 0x99, 0x47, 0x76, 0x3b, 0x61, 0xee, 0x45, 0x39, 0x13, 0x13, 0x38, 0x49, 0x4f, 0xe6, 0x7d, 0x8e, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x04, 0x47, 0x30, 0x45, 0x02, 0x21, 0x00, 0xd8, 0x2c, 0xa5, 0xd9, 0x9f, 0xba, 0x0f, 0x44, 0x33, 0xdf, 0x83, 0xde, 0x0a, 0xe8, 0x88, 0x85, 0xdb, 0x43, 0xd8, 0x14, 0xb5, 0x53, 0x26, 0x0a, 0x20, 0x82, 0x65, 0xee, 0x20, 0x80, 0xba, 0x27, 0x02, 0x20, 0x7f, 0x84, 0x07, 0x95, 0x99, 0x16, 0x07, 0x04, 0x2a, 0xf5, 0xa4, 0xd9, 0xe9, 0x24, 0x52, 0x83, 0x22, 0x54, 0xc3, 0x68, 0x0c, 0x10, 0x37, 0xb2, 0x7f, 0x27, 0x81, 0x43, 0x9c, 0x69, 0xf0, 0xab, 0x30, 0x02, 0x20, 0x7c, 0xfd, 0xbe, 0x87, 0xd5, 0xe1, 0xcf, 0xe1, 0xc7, 0x88, 0xe2, 0x84, 0x96, 0x0e, 0xff, 0x52, 0x77, 0xd7, 0x06, 0xc5, 0x15, 0xe1, 0x73, 0x9e, 0x33, 0xc8, 0x51, 0x9b, 0xe9, 0xd8, 0xd9, 0x92, 0x24, 0x03, 0x00, 0x18, 
[1688538660.772297][66408:66410] CHIP:DMG: 					] (277 bytes)
[1688538660.772301][66408:66410] CHIP:DMG: 					0x1 = [
[1688538660.772310][66408:66410] CHIP:DMG: 							0x4a, 0xf9, 0x18, 0xc9, 0x79, 0x43, 0xa1, 0xba, 0x6a, 0xc0, 0x6b, 0xd7, 0x57, 0x66, 0xb3, 0xc8, 0x75, 0x76, 0xba, 0x5b, 0x48, 0x87, 0x5d, 0xc3, 0x65, 0xa1, 0x39, 0x62, 0x26, 0x72, 0x0a, 0x3b, 0x94, 0x38, 0x8e, 0x6d, 0x60, 0xa0, 0xa0, 0xb8, 0x1a, 0x41, 0xce, 0x27, 0x3a, 0xca, 0x18, 0x10, 0xeb, 0x90, 0x6a, 0x1c, 0xaf, 0xc3, 0xb1, 0xf6, 0x88, 0x2d, 0xd8, 0xc7, 0xa2, 0x85, 0x30, 0x91, 
[1688538660.772316][66408:66410] CHIP:DMG: 					] (64 bytes)
[1688538660.772322][66408:66410] CHIP:DMG: 				},
[1688538660.772325][66408:66410] CHIP:DMG: 			},
[1688538660.772329][66408:66410] CHIP:DMG: 			
[1688538660.772332][66408:66410] CHIP:DMG: 		},
[1688538660.772335][66408:66410] CHIP:DMG: 		
[1688538660.772337][66408:66410] CHIP:DMG: 	],
[1688538660.772342][66408:66410] CHIP:DMG: 	
[1688538660.772344][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538660.772346][66408:66410] CHIP:DMG: },
[1688538660.772358][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1688538660.772364][66408:66410] CHIP:CTL: Received Attestation Information from the device
[1688538660.772370][66408:66410] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest'
[1688538660.772374][66408:66410] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 277/277
[1688538660.772379][66408:66410] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1688538660.772383][66408:66410] CHIP:CTL: Performing next commissioning step 'AttestationVerification'
[1688538660.772385][66408:66410] CHIP:CTL: Verifying attestation
[1688538660.778170][66408:66410] CHIP:CTL: Failed in verifying 'Attestation Information' command received from the device: err 101. Look at AttestationVerificationResult enum to understand the errors
[1688538660.778185][66408:66410] CHIP:CTL: Proceeding without changing fail-safe timer value as delegate has not set it
[1688538660.778189][66408:66410] CHIP:CTL: Device attestation completed, delegating continuation to client
[1688538660.778191][66408:66410] CHIP:CTL: Continuing commissioning after attestation failure for device ID 0x0000000000005430
[1688538660.778193][66408:66410] CHIP:CTL: Overriding attestation failure per client and continuing commissioning
[1688538660.778196][66408:66410] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification'
[1688538660.778198][66408:66410] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest'
[1688538660.778219][66408:66410] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest'
[1688538660.778222][66408:66410] CHIP:CTL: Sending CSR request to 0x7f1fc4017c90 device
[1688538660.778238][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538660.778243][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538660.778261][66408:66410] CHIP:EM: <<< [E:53079i S:15257 M:213358147] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538660.778267][66408:66410] CHIP:IN: (S) Sending msg 213358147 on secure session with LSID: 15257
[1688538660.778364][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538660.778373][66408:66410] CHIP:CTL: Sent CSR request, waiting for the CSR
[1688538660.778386][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538660.860298][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538660.863399][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.863425][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.951813][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538660.951903][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538660.951955][66408:66410] CHIP:EM: >>> [E:53079i S:15257 M:171851825] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538660.951965][66408:66410] CHIP:EM: Found matching exchange: 53079i, Delegate: 0x7f1fcc06afb8
[1688538660.951973][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538660.951985][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538660.951987][66408:66410] CHIP:DMG: {
[1688538660.951990][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538660.951992][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538660.951999][66408:66410] CHIP:DMG: 	[
[1688538660.952002][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538660.952008][66408:66410] CHIP:DMG: 		{
[1688538660.952012][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538660.952016][66408:66410] CHIP:DMG: 			{
[1688538660.952020][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538660.952025][66408:66410] CHIP:DMG: 				{
[1688538660.952030][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538660.952034][66408:66410] CHIP:DMG: 					ClusterId = 0x3e,
[1688538660.952039][66408:66410] CHIP:DMG: 					CommandId = 0x5,
[1688538660.952042][66408:66410] CHIP:DMG: 				},
[1688538660.952047][66408:66410] CHIP:DMG: 				
[1688538660.952050][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538660.952054][66408:66410] CHIP:DMG: 				{
[1688538660.952057][66408:66410] CHIP:DMG: 					0x0 = [
[1688538660.952075][66408:66410] CHIP:DMG: 							0x15, 0x30, 0x01, 0xdc, 0x30, 0x81, 0xd9, 0x30, 0x81, 0x81, 0x02, 0x01, 0x00, 0x30, 0x0e, 0x31, 0x0c, 0x30, 0x0a, 0x06, 0x03, 0x55, 0x04, 0x0b, 0x0c, 0x03, 0x43, 0x53, 0x41, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x08, 0x3b, 0x74, 0x67, 0x1f, 0xb0, 0x09, 0xa0, 0xb5, 0x51, 0x44, 0x14, 0xbd, 0x26, 0xe8, 0x0d, 0xb8, 0x85, 0x4c, 0x5e, 0x93, 0x4f, 0x37, 0x06, 0xc2, 0x17, 0xdb, 0x0e, 0xd3, 0x2e, 0xdb, 0x2c, 0xd5, 0x62, 0xfa, 0x2b, 0xa3, 0x8a, 0xc8, 0x3f, 0x2f, 0x77, 0x76, 0x02, 0x6e, 0x3f, 0xcf, 0x6e, 0x00, 0xbd, 0xf8, 0xbc, 0x2d, 0x78, 0xb8, 0x70, 0x7c, 0x94, 0x9f, 0x72, 0xe2, 0x69, 0xfc, 0xdb, 0xa0, 0x11, 0x30, 0x0f, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x09, 0x0e, 0x31, 0x02, 0x30, 0x00, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x03, 0x47, 0x00, 0x30, 0x44, 0x02, 0x20, 0x73, 0x33, 0x87, 0xb3, 0x6c, 0x31, 0x33, 0xa9, 0xa6, 0x95, 0x76, 0x14, 0x65, 0x15, 0xdf, 0xa8, 0x19, 0x2f, 0x5a, 0x54, 0x5a, 0x30, 0x11, 0xc6, 0x62, 0xc2, 0x1f, 0x81, 0xc4, 0x4c, 0x5a, 0xd0, 0x02, 0x20, 0x24, 0x1e, 0x57, 0x49, 0x47, 0x5e, 0x7f, 0x1e, 0x1f, 0x78, 0xcc, 0x7e, 0x2d, 0x87, 0xc8, 0x1a, 0x80, 0x59, 0x83, 0x5b, 0xc9, 0x51, 0x80, 0x7d, 0x56, 0x27, 0x53, 0xb6, 0xe2, 0x92, 0x4a, 0xae, 0x30, 0x02, 0x20, 0x06, 0xa8, 0xf7, 0xf4, 0xc3, 0x45, 0x42, 0x19, 0x2b, 0x20, 0xa8, 0x02, 0xf6, 0x8f, 0xcd, 0x29, 0x58, 0x50, 0xc0, 0xd2, 0x19, 0xd8, 0x6b, 0x10, 0x22, 0xa1, 0x87, 0xc0, 0x45, 0x3f, 0x27, 0x44, 0x18, 
[1688538660.952086][66408:66410] CHIP:DMG: 					] (260 bytes)
[1688538660.952089][66408:66410] CHIP:DMG: 					0x1 = [
[1688538660.952096][66408:66410] CHIP:DMG: 							0xa0, 0x88, 0x58, 0x7d, 0x6a, 0x3d, 0x8f, 0x30, 0x92, 0xe3, 0xb6, 0xa2, 0xd8, 0x7f, 0x64, 0x6f, 0xc5, 0xb4, 0xb6, 0x9e, 0xd9, 0xf1, 0x03, 0x1d, 0xc5, 0x22, 0x96, 0xe2, 0xe0, 0x62, 0x0a, 0x1f, 0xc2, 0x6a, 0x5f, 0x9f, 0xb6, 0x0b, 0x63, 0x11, 0xa8, 0xb1, 0xea, 0x0b, 0x78, 0x84, 0x8a, 0xb3, 0x11, 0x3b, 0xba, 0x9a, 0xfe, 0xcd, 0x5e, 0xe0, 0x93, 0xaa, 0xc6, 0x23, 0xff, 0xbf, 0x0c, 0x6b, 
[1688538660.952101][66408:66410] CHIP:DMG: 					] (64 bytes)
[1688538660.952106][66408:66410] CHIP:DMG: 				},
[1688538660.952108][66408:66410] CHIP:DMG: 			},
[1688538660.952112][66408:66410] CHIP:DMG: 			
[1688538660.952115][66408:66410] CHIP:DMG: 		},
[1688538660.952118][66408:66410] CHIP:DMG: 		
[1688538660.952120][66408:66410] CHIP:DMG: 	],
[1688538660.952125][66408:66410] CHIP:DMG: 	
[1688538660.952127][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538660.952129][66408:66410] CHIP:DMG: },
[1688538660.952142][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1688538660.952148][66408:66410] CHIP:CTL: Received certificate signing request from the device
[1688538660.952155][66408:66410] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest'
[1688538660.952158][66408:66410] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
[1688538660.952163][66408:66410] CHIP:CTL: Performing next commissioning step 'ValidateCSR'
[1688538660.960564][66408:66410] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR'
[1688538660.960571][66408:66410] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
[1688538660.960575][66408:66410] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain'
[1688538660.960578][66408:66410] CHIP:CTL: Getting certificate chain for the device from the issuer
[1688538660.960596][66408:66410] CHIP:CTL: Verifying Certificate Signing Request
[1688538660.968341][66408:66410] CHIP:CTL: Generating NOC
[1688538660.971524][66408:66410] CHIP:CTL: Providing certificate chain to the commissioner
[1688538660.971534][66408:66410] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status src/controller/ExampleOperationalCredentialsIssuer.cpp:396: Success
[1688538660.971541][66408:66410] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain'
[1688538660.971578][66408:66410] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert'
[1688538660.971580][66408:66410] CHIP:CTL: Sending root certificate to the device
[1688538660.971600][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538660.971605][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538660.971632][66408:66410] CHIP:EM: <<< [E:53080i S:15257 M:213358148] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538660.971637][66408:66410] CHIP:IN: (S) Sending msg 213358148 on secure session with LSID: 15257
[1688538660.971748][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538660.971754][66408:66410] CHIP:CTL: Sent root certificate to the device
[1688538660.971831][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538661.040818][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538661.130618][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538661.131683][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538661.131743][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538661.131836][66408:66410] CHIP:EM: >>> [E:53080i S:15257 M:171851826] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538661.131854][66408:66410] CHIP:EM: Found matching exchange: 53080i, Delegate: 0x7f1fcc06ae58
[1688538661.131865][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538661.131886][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538661.131891][66408:66410] CHIP:DMG: {
[1688538661.131896][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538661.131906][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538661.131916][66408:66410] CHIP:DMG: 	[
[1688538661.131922][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538661.131931][66408:66410] CHIP:DMG: 		{
[1688538661.131938][66408:66410] CHIP:DMG: 			CommandStatusIB =
[1688538661.131946][66408:66410] CHIP:DMG: 			{
[1688538661.131952][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538661.131960][66408:66410] CHIP:DMG: 				{
[1688538661.131968][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538661.131975][66408:66410] CHIP:DMG: 					ClusterId = 0x3e,
[1688538661.131983][66408:66410] CHIP:DMG: 					CommandId = 0xb,
[1688538661.131989][66408:66410] CHIP:DMG: 				},
[1688538661.131999][66408:66410] CHIP:DMG: 				
[1688538661.132005][66408:66410] CHIP:DMG: 				StatusIB =
[1688538661.132012][66408:66410] CHIP:DMG: 				{
[1688538661.132020][66408:66410] CHIP:DMG: 					status = 0x00 (SUCCESS),
[1688538661.132026][66408:66410] CHIP:DMG: 				},
[1688538661.132032][66408:66410] CHIP:DMG: 				
[1688538661.132038][66408:66410] CHIP:DMG: 			},
[1688538661.132047][66408:66410] CHIP:DMG: 			
[1688538661.132053][66408:66410] CHIP:DMG: 		},
[1688538661.132064][66408:66410] CHIP:DMG: 		
[1688538661.132070][66408:66410] CHIP:DMG: 	],
[1688538661.132080][66408:66410] CHIP:DMG: 	
[1688538661.132086][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538661.132092][66408:66410] CHIP:DMG: },
[1688538661.132117][66408:66410] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1688538661.132126][66408:66410] CHIP:CTL: Device confirmed that it has received the root certificate
[1688538661.132137][66408:66410] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert'
[1688538661.132144][66408:66410] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1688538661.132153][66408:66410] CHIP:CTL: Performing next commissioning step 'SendNOC'
[1688538661.132193][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538661.132206][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538661.132245][66408:66410] CHIP:EM: <<< [E:53081i S:15257 M:213358149] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538661.132258][66408:66410] CHIP:IN: (S) Sending msg 213358149 on secure session with LSID: 15257
[1688538661.132495][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538661.132521][66408:66410] CHIP:CTL: Sent operational certificate to the device
[1688538661.132553][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538661.220801][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538661.355898][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538661.404389][66408:66410] CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:154: CHIP Error 0x00000032: Timeout
[1688538661.445754][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538661.492204][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538661.492324][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538661.492421][66408:66410] CHIP:EM: >>> [E:53081i S:15257 M:171851827] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538661.492437][66408:66410] CHIP:EM: Found matching exchange: 53081i, Delegate: 0x7f1fcc06afb8
[1688538661.492452][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538661.492478][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538661.492486][66408:66410] CHIP:DMG: {
[1688538661.492494][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538661.492503][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538661.492519][66408:66410] CHIP:DMG: 	[
[1688538661.492525][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538661.492540][66408:66410] CHIP:DMG: 		{
[1688538661.492548][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538661.492557][66408:66410] CHIP:DMG: 			{
[1688538661.492567][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538661.492578][66408:66410] CHIP:DMG: 				{
[1688538661.492589][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538661.492600][66408:66410] CHIP:DMG: 					ClusterId = 0x3e,
[1688538661.492610][66408:66410] CHIP:DMG: 					CommandId = 0x8,
[1688538661.492621][66408:66410] CHIP:DMG: 				},
[1688538661.492643][66408:66410] CHIP:DMG: 				
[1688538661.492651][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538661.492662][66408:66410] CHIP:DMG: 				{
[1688538661.492673][66408:66410] CHIP:DMG: 					0x0 = 0, 
[1688538661.492684][66408:66410] CHIP:DMG: 					0x1 = 1, 
[1688538661.492695][66408:66410] CHIP:DMG: 				},
[1688538661.492703][66408:66410] CHIP:DMG: 			},
[1688538661.492719][66408:66410] CHIP:DMG: 			
[1688538661.492726][66408:66410] CHIP:DMG: 		},
[1688538661.492740][66408:66410] CHIP:DMG: 		
[1688538661.492747][66408:66410] CHIP:DMG: 	],
[1688538661.492763][66408:66410] CHIP:DMG: 	
[1688538661.492770][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538661.492778][66408:66410] CHIP:DMG: },
[1688538661.492809][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1688538661.492826][66408:66410] CHIP:CTL: Device returned status 0 on receiving the NOC
[1688538661.492833][66408:66410] CHIP:CTL: Operational credentials provisioned on device 0x7f1fc4017c90
[1688538661.492840][66408:66410] CHIP:TOO: Secure Pairing Success
[1688538661.492848][66408:66410] CHIP:TOO: CASE establishment successful
[1688538661.492860][66408:66410] CHIP:CTL: Successfully finished commissioning step 'SendNOC'
[1688538661.492868][66408:66410] CHIP:CTL: No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks
[1688538661.492876][66408:66410] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup'
[1688538661.492929][66408:66410] CHIP:CTL: Performing next commissioning step 'ThreadNetworkSetup'
[1688538661.492962][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538661.492974][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538661.493013][66408:66410] CHIP:EM: <<< [E:53082i S:15257 M:213358150] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538661.493028][66408:66410] CHIP:IN: (S) Sending msg 213358150 on secure session with LSID: 15257
[1688538661.493294][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538661.493324][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538661.580830][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538661.627021][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538661.627089][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538661.627189][66408:66410] CHIP:EM: >>> [E:53082i S:15257 M:171851828] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538661.627222][66408:66410] CHIP:EM: Found matching exchange: 53082i, Delegate: 0x7f1fcc06ae58
[1688538661.627239][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538661.627265][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538661.627273][66408:66410] CHIP:DMG: {
[1688538661.627282][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538661.627296][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538661.627311][66408:66410] CHIP:DMG: 	[
[1688538661.627318][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538661.627333][66408:66410] CHIP:DMG: 		{
[1688538661.627346][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538661.627360][66408:66410] CHIP:DMG: 			{
[1688538661.627364][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538661.627375][66408:66410] CHIP:DMG: 				{
[1688538661.627391][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538661.627397][66408:66410] CHIP:DMG: 					ClusterId = 0x31,
[1688538661.627408][66408:66410] CHIP:DMG: 					CommandId = 0x5,
[1688538661.627415][66408:66410] CHIP:DMG: 				},
[1688538661.627424][66408:66410] CHIP:DMG: 				
[1688538661.627434][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538661.627443][66408:66410] CHIP:DMG: 				{
[1688538661.627451][66408:66410] CHIP:DMG: 					0x0 = 0, 
[1688538661.627458][66408:66410] CHIP:DMG: 					0x2 = 0, 
[1688538661.627470][66408:66410] CHIP:DMG: 				},
[1688538661.627479][66408:66410] CHIP:DMG: 			},
[1688538661.627494][66408:66410] CHIP:DMG: 			
[1688538661.627501][66408:66410] CHIP:DMG: 		},
[1688538661.627516][66408:66410] CHIP:DMG: 		
[1688538661.627522][66408:66410] CHIP:DMG: 	],
[1688538661.627537][66408:66410] CHIP:DMG: 	
[1688538661.627545][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538661.627552][66408:66410] CHIP:DMG: },
[1688538661.627585][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1688538661.627628][66408:66410] CHIP:CTL: Received NetworkConfig response, networkingStatus=0
[1688538661.627640][66408:66410] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkSetup'
[1688538661.627650][66408:66410] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkSetup' -> 'FailsafeBeforeThreadEnable'
[1688538661.627662][66408:66410] CHIP:CTL: Performing next commissioning step 'FailsafeBeforeThreadEnable'
[1688538661.627678][66408:66410] CHIP:CTL: Arming failsafe (132 seconds)
[1688538661.627706][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538661.627718][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538661.627757][66408:66410] CHIP:EM: <<< [E:53083i S:15257 M:213358151] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538661.627772][66408:66410] CHIP:IN: (S) Sending msg 213358151 on secure session with LSID: 15257
[1688538661.627998][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538661.628026][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538661.716784][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538661.717040][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538661.717128][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538661.717246][66408:66410] CHIP:EM: >>> [E:53083i S:15257 M:171851829] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538661.717267][66408:66410] CHIP:EM: Found matching exchange: 53083i, Delegate: 0x7f1fcc06afb8
[1688538661.717282][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538661.717306][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538661.717312][66408:66410] CHIP:DMG: {
[1688538661.717317][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538661.717325][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538661.717342][66408:66410] CHIP:DMG: 	[
[1688538661.717349][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538661.717365][66408:66410] CHIP:DMG: 		{
[1688538661.717374][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538661.717383][66408:66410] CHIP:DMG: 			{
[1688538661.717392][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538661.717401][66408:66410] CHIP:DMG: 				{
[1688538661.717414][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538661.717423][66408:66410] CHIP:DMG: 					ClusterId = 0x30,
[1688538661.717435][66408:66410] CHIP:DMG: 					CommandId = 0x1,
[1688538661.717444][66408:66410] CHIP:DMG: 				},
[1688538661.717457][66408:66410] CHIP:DMG: 				
[1688538661.717466][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538661.717477][66408:66410] CHIP:DMG: 				{
[1688538661.717489][66408:66410] CHIP:DMG: 					0x0 = 0, 
[1688538661.717502][66408:66410] CHIP:DMG: 					0x1 = "" (0 chars), 
[1688538661.717512][66408:66410] CHIP:DMG: 				},
[1688538661.717521][66408:66410] CHIP:DMG: 			},
[1688538661.717536][66408:66410] CHIP:DMG: 			
[1688538661.717543][66408:66410] CHIP:DMG: 		},
[1688538661.717558][66408:66410] CHIP:DMG: 		
[1688538661.717565][66408:66410] CHIP:DMG: 	],
[1688538661.717580][66408:66410] CHIP:DMG: 	
[1688538661.717587][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538661.717594][66408:66410] CHIP:DMG: },
[1688538661.717626][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1688538661.717641][66408:66410] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1688538661.717652][66408:66410] CHIP:CTL: Successfully finished commissioning step 'FailsafeBeforeThreadEnable'
[1688538661.717658][66408:66410] CHIP:CTL: Commissioning stage next step: 'FailsafeBeforeThreadEnable' -> 'ThreadNetworkEnable'
[1688538661.717668][66408:66410] CHIP:CTL: Performing next commissioning step 'ThreadNetworkEnable'
[1688538661.717728][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538661.717739][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538661.717786][66408:66410] CHIP:EM: <<< [E:53084i S:15257 M:213358152] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538661.717800][66408:66410] CHIP:IN: (S) Sending msg 213358152 on secure session with LSID: 15257
[1688538661.718012][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538661.718045][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538661.806007][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538662.301662][66408:66410] CHIP:DL: Re-trying resolve
[1688538662.302833][66408:66410] CHIP:DL: Re-trying resolve
[1688538663.562373][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538663.562478][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538663.562577][66408:66410] CHIP:EM: >>> [E:53084i S:15257 M:171851830] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538663.562594][66408:66410] CHIP:EM: Found matching exchange: 53084i, Delegate: 0x7f1fcc06ae58
[1688538663.562606][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538663.562629][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538663.562635][66408:66410] CHIP:DMG: {
[1688538663.562640][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538663.562645][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538663.562658][66408:66410] CHIP:DMG: 	[
[1688538663.562665][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538663.562677][66408:66410] CHIP:DMG: 		{
[1688538663.562683][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538663.562691][66408:66410] CHIP:DMG: 			{
[1688538663.562698][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538663.562709][66408:66410] CHIP:DMG: 				{
[1688538663.562717][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538663.562726][66408:66410] CHIP:DMG: 					ClusterId = 0x31,
[1688538663.562734][66408:66410] CHIP:DMG: 					CommandId = 0x7,
[1688538663.562741][66408:66410] CHIP:DMG: 				},
[1688538663.562753][66408:66410] CHIP:DMG: 				
[1688538663.562759][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538663.562768][66408:66410] CHIP:DMG: 				{
[1688538663.562777][66408:66410] CHIP:DMG: 					0x0 = 0, 
[1688538663.562785][66408:66410] CHIP:DMG: 					0x2 = NULL
[1688538663.562793][66408:66410] CHIP:DMG: 				},
[1688538663.562799][66408:66410] CHIP:DMG: 			},
[1688538663.562809][66408:66410] CHIP:DMG: 			
[1688538663.562815][66408:66410] CHIP:DMG: 		},
[1688538663.562825][66408:66410] CHIP:DMG: 		
[1688538663.562831][66408:66410] CHIP:DMG: 	],
[1688538663.562842][66408:66410] CHIP:DMG: 	
[1688538663.562849][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538663.562855][66408:66410] CHIP:DMG: },
[1688538663.562882][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1688538663.562898][66408:66410] CHIP:CTL: Received ConnectNetwork response, networkingStatus=0
[1688538663.562911][66408:66410] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkEnable'
[1688538663.562919][66408:66410] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkEnable' -> 'FindOperational'
[1688538663.562928][66408:66410] CHIP:CTL: Performing next commissioning step 'FindOperational'
[1688538663.562935][66408:66410] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000005430]
[1688538663.562941][66408:66410] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1688538663.562977][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 1 --> 2
[1688538663.562987][66408:66410] CHIP:DIS: Resolving A5C323195DA1338E:0000000000005430 ...
[1688538663.563733][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538663.763162][66408:66410] CHIP:DIS: Checking node lookup status after 200 ms
[1688538666.260944][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538667.303503][66408:66410] CHIP:DL: Re-trying resolve
[1688538667.304827][66408:66410] CHIP:DL: Re-trying resolve
[1688538667.608709][66408:66410] CHIP:DL: Avahi resolve found
[1688538667.608771][66408:66410] CHIP:DIS: Node ID resolved for A5C323195DA1338E:0000000000005430
[1688538667.608779][66408:66410] CHIP:DIS: 	Hostname: A6448819020DB534
[1688538667.608788][66408:66410] CHIP:DIS: 	IP Address #1: fd11:22::f222:7f86:5acf:da40
[1688538667.608798][66408:66410] CHIP:DIS: 	Port: 5540
[1688538667.608810][66408:66410] CHIP:DIS: 	Mrp Interval idle: 5000 ms
[1688538667.608822][66408:66410] CHIP:DIS: 	Mrp Interval active: 300 ms
[1688538667.608830][66408:66410] CHIP:DIS: 	TCP Supported: 0
[1688538667.609167][66408:66410] CHIP:DIS: Lookup clearing interface for non LL address
[1688538667.609208][66408:66410] CHIP:DIS: UDP:[fd11:22::f222:7f86:5acf:da40%otbr0]:5540: new best score: 4
[1688538667.609218][66408:66410] CHIP:DIS: Checking node lookup status after 4046 ms
[1688538667.609236][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: Updating device address to UDP:[fd11:22::f222:7f86:5acf:da40]:5540 while in state 2
[1688538667.609245][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 2 --> 3
[1688538667.609294][66408:66410] CHIP:IN: SecureSession[0x7f1fc401df10]: Allocated Type:2 LSID:15258
[1688538667.609314][66408:66410] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000005430
[1688538667.616908][66408:66410] CHIP:EM: <<< [E:53085i S:0 M:33670169] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1688538667.616938][66408:66410] CHIP:IN: (U) Sending msg 33670169 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538667.617025][66408:66410] CHIP:SC: Sent Sigma1 msg
[1688538667.617036][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 3 --> 4
[1688538668.821028][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538668.821104][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538670.492467][66408:66409] CHIP:DL: Got IP address on interface: wlp3s0 IP: 192.168.219.214
[1688538670.492565][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 32770
[1688538671.525906][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538672.307519][66408:66410] CHIP:DL: Avahi resolve failed
[1688538672.308179][66408:66410] CHIP:DL: Avahi resolve failed
[1688538674.084819][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538674.084938][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538674.193307][66408:66410] CHIP:EM: Retransmitting MessageCounter:33670169 on exchange 53085i Send Cnt 1
[1688538674.193354][66408:66410] CHIP:IN: (U) Sending msg 33670169 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538676.791882][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538679.348866][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538679.349013][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538680.888833][66408:66410] CHIP:EM: Retransmitting MessageCounter:33670169 on exchange 53085i Send Cnt 2
[1688538680.888890][66408:66410] CHIP:IN: (U) Sending msg 33670169 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538682.052510][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538684.612876][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538684.612960][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538687.311694][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538689.868737][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538689.868824][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538691.256273][66408:66410] CHIP:EM: Retransmitting MessageCounter:33670169 on exchange 53085i Send Cnt 3
[1688538691.256328][66408:66410] CHIP:IN: (U) Sending msg 33670169 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538692.572134][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538695.128843][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538695.128928][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538697.832021][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538700.388956][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538700.389040][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538703.092076][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538705.655833][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538705.655884][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538705.656986][66408:66410] CHIP:EM: Retransmitting MessageCounter:33670169 on exchange 53085i Send Cnt 4
[1688538705.657010][66408:66410] CHIP:IN: (U) Sending msg 33670169 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538708.396960][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538710.953226][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538710.953370][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538713.657786][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538716.212603][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538716.212686][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538718.918498][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538721.473070][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538721.473201][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538724.179773][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538725.969673][66408:66409] CHIP:DL: Got IP address on interface: wlp3s0 IP: 192.168.219.214
[1688538725.969769][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 32770
[1688538726.737080][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538726.737222][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538729.485295][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538730.900885][66408:66410] CHIP:EM: Failed to Send CHIP MessageCounter:33670169 on exchange 53085i sendCount: 4 max retries: 4
[1688538731.914316][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538731.914450][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538734.611342][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538737.169115][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538737.169190][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538739.872839][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538740.095135][66408:66410] CHIP:SC: CASESession timed out while waiting for a response from the peer. Current state was 1
[1688538740.095180][66408:66410] CHIP:IN: SecureSession[0x7f1fc401df10]: Released - Type:2 LSID:15258
[1688538740.095200][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 4 --> 2
[1688538740.095214][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 2 --> 1
[1688538740.095230][66408:66410] CHIP:DIS: OperationalSessionSetup:attempts done: 1, attempts left: 2, retry delay 1s, status src/system/SystemLayerImplSelect.cpp:167: Success
[1688538740.095237][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 1 --> 6
[1688538740.095254][66408:66410] CHIP:CTL: Session establishment failed for <0000000000005430, 1>, error: src/protocols/secure_channel/CASESession.cpp:485: CHIP Error 0x00000032: Timeout.  Next retry expected to get a response to Sigma1 or fail within 8 seconds
[1688538740.095266][66408:66410] CHIP:CTL: Arming failsafe (68 seconds)
[1688538740.095303][66408:66410] CHIP:DMG: ICR moving to [AddingComm]
[1688538740.095313][66408:66410] CHIP:DMG: ICR moving to [AddedComma]
[1688538740.095365][66408:66410] CHIP:EM: <<< [E:53086i S:15257 M:213358153] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1688538740.095384][66408:66410] CHIP:IN: (S) Sending msg 213358153 on secure session with LSID: 15257
[1688538740.095717][66408:66410] CHIP:DMG: ICR moving to [CommandSen]
[1688538740.187745][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538740.190156][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538740.190248][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538740.190337][66408:66410] CHIP:EM: >>> [E:53086i S:15257 M:171851831] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1688538740.190351][66408:66410] CHIP:EM: Found matching exchange: 53086i, Delegate: 0x7f1fcc06afb8
[1688538740.190364][66408:66410] CHIP:DMG: ICR moving to [ResponseRe]
[1688538740.190386][66408:66410] CHIP:DMG: InvokeResponseMessage =
[1688538740.190392][66408:66410] CHIP:DMG: {
[1688538740.190399][66408:66410] CHIP:DMG: 	suppressResponse = false, 
[1688538740.190407][66408:66410] CHIP:DMG: 	InvokeResponseIBs =
[1688538740.190418][66408:66410] CHIP:DMG: 	[
[1688538740.190423][66408:66410] CHIP:DMG: 		InvokeResponseIB =
[1688538740.190435][66408:66410] CHIP:DMG: 		{
[1688538740.190441][66408:66410] CHIP:DMG: 			CommandDataIB =
[1688538740.190447][66408:66410] CHIP:DMG: 			{
[1688538740.190453][66408:66410] CHIP:DMG: 				CommandPathIB =
[1688538740.190462][66408:66410] CHIP:DMG: 				{
[1688538740.190470][66408:66410] CHIP:DMG: 					EndpointId = 0x0,
[1688538740.190477][66408:66410] CHIP:DMG: 					ClusterId = 0x30,
[1688538740.190485][66408:66410] CHIP:DMG: 					CommandId = 0x1,
[1688538740.190491][66408:66410] CHIP:DMG: 				},
[1688538740.190499][66408:66410] CHIP:DMG: 				
[1688538740.190506][66408:66410] CHIP:DMG: 				CommandFields = 
[1688538740.190514][66408:66410] CHIP:DMG: 				{
[1688538740.190522][66408:66410] CHIP:DMG: 					0x0 = 0, 
[1688538740.190531][66408:66410] CHIP:DMG: 					0x1 = "" (0 chars), 
[1688538740.190538][66408:66410] CHIP:DMG: 				},
[1688538740.190544][66408:66410] CHIP:DMG: 			},
[1688538740.190553][66408:66410] CHIP:DMG: 			
[1688538740.190559][66408:66410] CHIP:DMG: 		},
[1688538740.190570][66408:66410] CHIP:DMG: 		
[1688538740.190575][66408:66410] CHIP:DMG: 	],
[1688538740.190586][66408:66410] CHIP:DMG: 	
[1688538740.190592][66408:66410] CHIP:DMG: 	InteractionModelRevision = 1
[1688538740.190597][66408:66410] CHIP:DMG: },
[1688538740.190626][66408:66410] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1688538740.190639][66408:66410] CHIP:CTL: Status of extending fail-safe for CASE retry: 0
[1688538740.190654][66408:66410] CHIP:DMG: ICR moving to [AwaitingDe]
[1688538741.095119][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 6 --> 2
[1688538741.095164][66408:66410] CHIP:DIS: Resolving A5C323195DA1338E:0000000000005430 ...
[1688538741.096481][66408:66410] CHIP:DL: Avahi resolve found
[1688538741.096528][66408:66410] CHIP:DIS: Node ID resolved for A5C323195DA1338E:0000000000005430
[1688538741.096535][66408:66410] CHIP:DIS: 	Hostname: A6448819020DB534
[1688538741.096543][66408:66410] CHIP:DIS: 	IP Address #1: fd11:22::f222:7f86:5acf:da40
[1688538741.096548][66408:66410] CHIP:DIS: 	Port: 5540
[1688538741.096552][66408:66410] CHIP:DIS: 	Mrp Interval idle: 5000 ms
[1688538741.096556][66408:66410] CHIP:DIS: 	Mrp Interval active: 300 ms
[1688538741.096564][66408:66410] CHIP:DIS: 	TCP Supported: 0
[1688538741.096899][66408:66410] CHIP:DIS: Lookup clearing interface for non LL address
[1688538741.096940][66408:66410] CHIP:DIS: UDP:[fd11:22::f222:7f86:5acf:da40%otbr0]:5540: new best score: 4
[1688538741.096949][66408:66410] CHIP:DIS: Checking node lookup status after 2 ms
[1688538741.096957][66408:66410] CHIP:DIS: Keeping DNSSD lookup active
[1688538741.295081][66408:66410] CHIP:DIS: Checking node lookup status after 200 ms
[1688538741.295131][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: Updating device address to UDP:[fd11:22::f222:7f86:5acf:da40]:5540 while in state 2
[1688538741.295143][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 2 --> 3
[1688538741.295189][66408:66410] CHIP:IN: SecureSession[0x7f1fc401df10]: Allocated Type:2 LSID:15259
[1688538741.295209][66408:66410] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000005430
[1688538741.301308][66408:66410] CHIP:EM: <<< [E:53087i S:0 M:33670170] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1688538741.301320][66408:66410] CHIP:IN: (U) Sending msg 33670170 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538741.301408][66408:66410] CHIP:SC: Sent Sigma1 msg
[1688538741.301416][66408:66410] CHIP:DIS: OperationalSessionSetup[1:0000000000005430]: State change 3 --> 4
[1688538742.886115][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538745.488877][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538745.489043][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538747.895141][66408:66410] CHIP:EM: Retransmitting MessageCounter:33670170 on exchange 53087i Send Cnt 1
[1688538747.895196][66408:66410] CHIP:IN: (U) Sending msg 33670170 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538748.193326][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538750.747782][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538750.747831][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538753.454986][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538753.568320][66408:66410] CHIP:EM: Retransmitting MessageCounter:33670170 on exchange 53087i Send Cnt 2
[1688538753.568376][66408:66410] CHIP:IN: (U) Sending msg 33670170 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538756.012966][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538756.013114][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538758.761543][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538761.272904][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538761.273017][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538763.516508][66408:66410] CHIP:EM: Retransmitting MessageCounter:33670170 on exchange 53087i Send Cnt 3
[1688538763.516564][66408:66410] CHIP:IN: (U) Sending msg 33670170 to IP address 'UDP:[fd11:22::f222:7f86:5acf:da40]:5540'
[1688538763.978405][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538766.532703][66408:66409] CHIP:DL: Indication received, conn = 0x7f1fcc068ff0
[1688538766.532772][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1688538769.239917][66408:66410] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1688538771.111126][66408:66408] CHIP:CTL: Shutting down the commissioner
[1688538771.111155][66408:66408] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688538771.111163][66408:66408] CHIP:DIS: Closing all BLE connections
[1688538771.111171][66408:66408] CHIP:IN: Clearing BLE pending packets.
[1688538771.111565][66408:66408] CHIP:BLE: Auto-closing end point's BLE connection.
[1688538771.111586][66408:66408] CHIP:DL: Closing BLE GATT connection (con 0x7f1fcc068ff0)
[1688538771.111737][66408:66409] CHIP:DL: BluezDisconnect peer=F0:82:C0:02:B4:7C
[1688538773.519373][66408:66408] CHIP:IN: SecureSession[0x7f1fc4007c60]: MarkForEviction Type:1 LSID:15257
[1688538773.519495][66408:66408] CHIP:SC: SecureSession[0x7f1fc4007c60]: Moving from state 'kActive' --> 'kPendingEviction'
[1688538773.519541][66408:66408] CHIP:IN: SecureSession[0x7f1fc4007c60]: Released - Type:1 LSID:15257
[1688538773.519577][66408:66408] CHIP:CTL: Shutting down the controller
[1688538773.519627][66408:66408] CHIP:IN: SecureSession[0x7f1fc401df10]: Released - Type:2 LSID:15259
[1688538773.519653][66408:66409] CHIP:DL: Bluez disconnected
[1688538773.519674][66408:66408] CHIP:CTL: Device connection failed. Error src/app/OperationalSessionSetup.cpp:438: CHIP Error 0x00000074: The operation has been cancelled
[1688538773.519701][66408:66408] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1688538773.519711][66408:66408] CHIP:FP: Forgetting fabric 0x1
[1688538773.519676][66408:66409] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1688538773.519730][66408:66408] CHIP:TS: Pending Last Known Good Time: 2023-06-01T07:38:45
[1688538773.519851][66408:66408] CHIP:TS: Previous Last Known Good Time: 2023-06-01T07:38:45
[1688538773.519858][66408:66408] CHIP:TS: Reverted Last Known Good Time to previous value
[1688538773.519873][66408:66408] CHIP:CTL: Shutting down the commissioner
[1688538773.519880][66408:66408] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1688538773.519887][66408:66408] CHIP:CTL: Shutting down the controller
[1688538773.519891][66408:66408] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1688538773.520504][66408:66408] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1688538773.520555][66408:66408] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1688538773.520580][66408:66408] CHIP:FP: Shutting down FabricTable
[1688538773.520596][66408:66408] CHIP:TS: Pending Last Known Good Time: 2023-06-01T07:38:45
[1688538773.520682][66408:66408] CHIP:TS: Previous Last Known Good Time: 2023-06-01T07:38:45
[1688538773.520691][66408:66408] CHIP:TS: Reverted Last Known Good Time to previous value
[1688538773.520889][66408:66408] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ZSkZbb)
[1688538773.521178][66408:66408] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1688538773.521204][66408:66408] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1688538773.521213][66408:66408] CHIP:DL: Inet Layer shutdown
[1688538773.521220][66408:66408] CHIP:DL: BLE shutdown
[1688538773.522106][66408:66408] CHIP:DL: System Layer shutdown
[1688538773.522305][66408:66408] CHIP:TOO: Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:537: CHIP Error 0x00000032: Timeout

And the OTBR log looks like this :

Evaluating routing policy
Jul  5 07:08:07 ab9a6b3a5310 otbr-agent[191]: 00:00:56.767 [I] BorderRouter--: Evaluating NAT64 prefix
Jul  5 07:08:07 ab9a6b3a5310 otbr-agent[191]: 00:00:56.767 [I] BorderRouter--: RouterAdvert: Added PIO for fd11:1111:1122:2222::/64 (valid=1800, preferred=1800)
Jul  5 07:08:07 ab9a6b3a5310 otbr-agent[191]: 00:00:56.767 [I] BorderRouter--: RouterAdvert: Added RIO for fd11:22:0:0::/64 (lifetime=1800)
Jul  5 07:08:07 ab9a6b3a5310 otbr-agent[191]: 00:00:56.767 [I] BorderRouter--: Sent Router Advertisement on infra netif 27
Jul  5 07:08:07 ab9a6b3a5310 otbr-agent[191]: 00:00:56.767 [I] BorderRouter--: Start evaluating routing policy, scheduled in 208932 milliseconds
Jul  5 07:08:07 ab9a6b3a5310 otbr-agent[191]: 00:00:56.767 [I] BorderRouter--: Received Router Advertisement from fe80:0:0:0:42:acff:fe12:2 on infra netif 27
Jul  5 07:08:10 ab9a6b3a5310 otbr-agent[191]: 00:00:59.737 [I] Mac-----------: Received Beacon Request
Jul  5 07:08:10 ab9a6b3a5310 otbr-agent[191]: 00:00:59.737 [I] Mac-----------: Sending Beacon
Jul  5 07:08:10 ab9a6b3a5310 otbr-agent[191]: 00:00:59.795 [I] Mac-----------: Frame rx failed, error:UnknownNeighbor, len:28, seqnum:90, type:Beacon, src:0x469b, dst:None, sec:no, ackreq:no
Jul  5 07:08:10 ab9a6b3a5310 otbr-agent[191]: 00:00:59.837 [I] Mac-----------: Frame rx failed, error:UnknownNeighbor, len:28, seqnum:149, type:Beacon, src:0x0000, dst:None, sec:no, ackreq:no
Jul  5 07:08:10 ab9a6b3a5310 otbr-agent[191]: 00:00:59.843 [I] Mac-----------: Frame rx failed, error:UnknownNeighbor, len:28, seqnum:132, type:Beacon, src:0x6f9b, dst:None, sec:no, ackreq:no
Jul  5 07:08:11 ab9a6b3a5310 otbr-agent[191]: 00:00:59.899 [I] Mac-----------: Received Beacon Request
Jul  5 07:08:11 ab9a6b3a5310 otbr-agent[191]: 00:00:59.900 [I] Mac-----------: Sending Beacon
Jul  5 07:08:11 ab9a6b3a5310 otbr-agent[191]: 00:00:59.974 [I] Mac-----------: Frame rx failed, error:UnknownNeighbor, len:28, seqnum:91, type:Beacon, src:0x469b, dst:None, sec:no, ackreq:no
Jul  5 07:08:11 ab9a6b3a5310 otbr-agent[191]: 00:00:59.985 [I] Mac-----------: Frame rx failed, error:UnknownNeighbor, len:28, seqnum:150, type:Beacon, src:0x0000, dst:None, sec:no, ackreq:no
Jul  5 07:08:11 ab9a6b3a5310 otbr-agent[191]: 00:01:00.011 [I] Mac-----------: Frame rx failed, error:UnknownNeighbor, len:28, seqnum:133, type:Beacon, src:0x6f9b, dst:None, sec:no, ackreq:no

Could anyone please help me to get rid of this error and could you please reply me fast as I have very less time to complete the project ?

[Kenneth]

I will see if someone can look into this, let me know if you have any findings in the meantime.

Kenenth

[Varun2103]

Yeah I think the problem is my OTBR is not getting the correct Wi-Fi interface of my linux, So could you explain me how exactly things work with OTBR, docker and host Wi-Fi interface ?

[Kenneth]

I encourage to go through this page about testing:
https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/nrf/protocols/matter/getting_started/testing/thread_one_otbr.html 

You need to do following action to have operational Thread Network created by Border router (after running docker):

Open the http://localhost:8080/ address in a web browser and choose Form from the menu.

You can try, before running the border router docker, run following commands to enable RA/ROI on created otbr interface:

sudo sysctl -w net.ipv6.conf.otbr0.accept_ra_rt_info_max_plen=128
sudo sysctl -w net.ipv6.conf.otbr0.accept_ra=2

Kenneth

[Varun2103]

Ok will do that, but can you say me what is otbr0 interface and why OTBR is always choosing backbone interface as eth0 even though my Linux PC is using Wi-Fi interface(wlp3s0) ?