Step 7 TM2 ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ./chip-tool pairing onnetwork-long 0xDEADBEEF 20202021 22 [1728020684.696306][50555:50555] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1728020684.697212][50555:50555] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1728020684.697244][50555:50555] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1728020684.702492][50555:50555] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1728020684.702759][50555:50555] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1728020684.702865][50555:50555] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1728020684.703199][50555:50555] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Pnllkr) [1728020684.703836][50555:50555] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1728020684.703892][50555:50555] CHIP:DL: NVS set: chip-counters/reboot-count = 3 (0x3) [1728020684.704831][50555:50555] CHIP:DL: Got Ethernet interface: eth0 [1728020684.705431][50555:50555] CHIP:DL: Found the primary Ethernet interface:eth0 [1728020684.706056][50555:50555] CHIP:DL: Got WiFi interface: wlan0 [1728020684.706123][50555:50555] CHIP:DL: Failed to reset WiFi statistic counts [1728020684.706174][50555:50555] CHIP:IN: UDP::Init bind&listen port=0 [1728020684.706274][50555:50555] CHIP:IN: UDP::Init bound to port=34466 [1728020684.706294][50555:50555] CHIP:IN: BLEBase::Init - setting/overriding transport [1728020684.706311][50555:50555] CHIP:IN: TransportMgr initialized [1728020684.706341][50555:50555] CHIP:FP: Initializing FabricTable from persistent storage [1728020684.706498][50555:50555] CHIP:TS: Last Known Good Time: 2023-10-03T16:51:18 [1728020684.707875][50555:50555] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x3551521866D894D5, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1 [1728020684.709809][50555:50555] CHIP:ZCL: Using ZAP configuration... [1728020684.713286][50555:50555] CHIP:DL: Avahi client registered [1728020684.713412][50555:50555] CHIP:CTL: System State Initialized... [1728020684.713559][50555:50555] CHIP:CTL: Setting attestation nonce to random value [1728020684.713594][50555:50555] CHIP:CTL: Setting CSR nonce to random value [1728020684.713650][50555:50555] CHIP:IN: UDP::Init bind&listen port=5550 [1728020684.713771][50555:50555] CHIP:IN: UDP::Init bound to port=5550 [1728020684.713792][50555:50555] CHIP:IN: TransportMgr initialized [1728020684.714029][50555:50557] CHIP:DL: CHIP task running [1728020684.714203][50555:50557] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1728020684.714477][50555:50557] CHIP:CTL: Setting attestation nonce to random value [1728020684.714632][50555:50557] CHIP:CTL: Setting CSR nonce to random value [1728020684.715474][50555:50557] CHIP:CTL: Generating NOC [1728020684.716308][50555:50557] CHIP:FP: Validating NOC chain [1728020684.717876][50555:50557] CHIP:FP: NOC chain validation successful [1728020684.718054][50555:50557] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669 [1728020684.718090][50555:50557] CHIP:TS: Last Known Good Time: 2023-10-03T16:51:18 [1728020684.718115][50555:50557] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1728020684.718137][50555:50557] CHIP:TS: Retaining current Last Known Good Time [1728020684.723199][50555:50557] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1728020684.725468][50555:50557] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-03T16:51:18 [1728020684.727876][50555:50557] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 3551521866D894D5) [1728020684.727938][50555:50557] CHIP:IN: UDP::Init bind&listen port=5550 [1728020684.728071][50555:50557] CHIP:IN: UDP::Init bound to port=5550 [1728020684.728099][50555:50557] CHIP:IN: TransportMgr initialized [1728020684.755514][50555:50557] CHIP:DL: Avahi browse: cache new [1728020684.755752][50555:50557] CHIP:DL: Avahi browse: cache new [1728020684.755845][50555:50557] CHIP:DL: Avahi browse: cache new [1728020684.756007][50555:50557] CHIP:DL: Avahi browse: cache new [1728020684.756211][50555:50557] CHIP:DL: Avahi browse: cache new [1728020684.756356][50555:50557] CHIP:DL: Avahi browse: cache new [1728020684.756439][50555:50557] CHIP:DL: Avahi browse: cache new [1728020684.756516][50555:50557] CHIP:DL: Avahi browse: cache new [1728020684.756678][50555:50557] CHIP:DL: Avahi browse: cache exhausted [1728020685.757722][50555:50557] CHIP:DL: Avahi browse: all for now [1728020685.765356][50555:50557] CHIP:DL: Avahi resolve found [1728020685.765486][50555:50557] CHIP:DIS: Discovered node: [1728020685.765515][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020685.765549][50555:50557] CHIP:DIS: IP Address #1: fe80::588e:4aff:fe48:458 [1728020685.765577][50555:50557] CHIP:DIS: Port: 5565 [1728020685.765604][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020685.765631][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020685.765656][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020685.765683][50555:50557] CHIP:DIS: Vendor ID: 65521 [1728020685.765708][50555:50557] CHIP:DIS: Product ID: 32769 [1728020685.765734][50555:50557] CHIP:DIS: Long Discriminator: 22 [1728020685.765760][50555:50557] CHIP:DIS: Pairing Hint: 33 [1728020685.765785][50555:50557] CHIP:DIS: Instance Name: 5F4B1ED24E3EC2E7 [1728020685.765811][50555:50557] CHIP:DIS: Commissioning Mode: 1 [1728020685.765851][50555:50557] CHIP:TOO: Discovered Device: fe80::588e:4aff:fe48:458:5565 [1728020685.766865][50555:50557] CHIP:IN: SecureSession[0xffff7c00ae70]: Allocated Type:1 LSID:25080 [1728020685.766913][50555:50557] CHIP:SC: Assigned local session key ID 25080 [1728020685.767160][50555:50557] CHIP:EM: <<< [E:24002i S:0 M:81919426] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) [1728020685.767512][50555:50557] CHIP:SC: Sent PBKDF param request [1728020685.767571][50555:50557] CHIP:CTL: Setting attestation nonce to random value [1728020685.767615][50555:50557] CHIP:CTL: Setting CSR nonce to random value [1728020685.767663][50555:50557] CHIP:CTL: Commission called for node ID 0x00000000DEADBEEF [1728020685.767701][50555:50557] CHIP:CTL: Unknown filter type; all matches will fail [1728020685.769124][50555:50557] CHIP:DL: Avahi resolve found [1728020685.769208][50555:50557] CHIP:DIS: Discovered node: [1728020685.769230][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020685.769258][50555:50557] CHIP:DIS: IP Address #1: fe80::ac06:dfff:fea9:5ab7 [1728020685.769280][50555:50557] CHIP:DIS: Port: 5565 [1728020685.769301][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020685.769322][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020685.769343][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020685.769364][50555:50557] CHIP:DIS: Vendor ID: 65521 [1728020685.769385][50555:50557] CHIP:DIS: Product ID: 32769 [1728020685.769405][50555:50557] CHIP:DIS: Long Discriminator: 22 [1728020685.769426][50555:50557] CHIP:DIS: Pairing Hint: 33 [1728020685.769446][50555:50557] CHIP:DIS: Instance Name: 5F4B1ED24E3EC2E7 [1728020685.769467][50555:50557] CHIP:DIS: Commissioning Mode: 1 [1728020685.769496][50555:50557] CHIP:CTL: Unknown filter type; all matches will fail [1728020685.770418][50555:50557] CHIP:EM: >>> [E:24002i S:0 M:181516365 (Ack:81919426)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) [1728020685.770464][50555:50557] CHIP:EM: Found matching exchange: 24002i, Delegate: 0xffff7c013800 [1728020685.770500][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:81919426 from Retrans Table on exchange 24002i [1728020685.770544][50555:50557] CHIP:SC: Received PBKDF param response [1728020685.770593][50555:50557] CHIP:SC: Peer assigned session ID 15596 [1728020685.770626][50555:50557] CHIP:SC: Found MRP parameters in the message [1728020685.777321][50555:50557] CHIP:EM: <<< [E:24002i S:0 M:81919427 (Ack:181516365)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:22 (SecureChannel:PASE_Pake1) [1728020685.777526][50555:50557] CHIP:SC: Sent spake2p msg1 [1728020685.777645][50555:50557] CHIP:DL: Avahi resolve found [1728020685.777713][50555:50557] CHIP:DIS: Discovered node: [1728020685.777734][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020685.777759][50555:50557] CHIP:DIS: IP Address #1: fe80::4c1f:d6ff:fef9:cf66 [1728020685.777781][50555:50557] CHIP:DIS: Port: 5565 [1728020685.777803][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020685.777825][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020685.777845][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020685.777867][50555:50557] CHIP:DIS: Vendor ID: 65521 [1728020685.777887][50555:50557] CHIP:DIS: Product ID: 32769 [1728020685.777907][50555:50557] CHIP:DIS: Long Discriminator: 22 [1728020685.777928][50555:50557] CHIP:DIS: Pairing Hint: 33 [1728020685.777949][50555:50557] CHIP:DIS: Instance Name: 5F4B1ED24E3EC2E7 [1728020685.777969][50555:50557] CHIP:DIS: Commissioning Mode: 1 [1728020685.777999][50555:50557] CHIP:CTL: Unknown filter type; all matches will fail [1728020685.778951][50555:50557] CHIP:DL: Avahi resolve found [1728020685.779023][50555:50557] CHIP:DIS: Discovered node: [1728020685.779045][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020685.779072][50555:50557] CHIP:DIS: IP Address #1: fe80::1c0c:c9ff:fee8:836b [1728020685.779094][50555:50557] CHIP:DIS: Port: 5565 [1728020685.779115][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020685.779136][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020685.779156][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020685.779176][50555:50557] CHIP:DIS: Vendor ID: 65521 [1728020685.779197][50555:50557] CHIP:DIS: Product ID: 32769 [1728020685.779217][50555:50557] CHIP:DIS: Long Discriminator: 22 [1728020685.779238][50555:50557] CHIP:DIS: Pairing Hint: 33 [1728020685.779258][50555:50557] CHIP:DIS: Instance Name: 5F4B1ED24E3EC2E7 [1728020685.779278][50555:50557] CHIP:DIS: Commissioning Mode: 1 [1728020685.779305][50555:50557] CHIP:CTL: Unknown filter type; all matches will fail [1728020685.780233][50555:50557] CHIP:DL: Avahi resolve found [1728020685.780304][50555:50557] CHIP:DIS: Discovered node: [1728020685.780325][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020685.780349][50555:50557] CHIP:DIS: IP Address #1: fe80::a830:ceff:fed2:d8b6 [1728020685.780369][50555:50557] CHIP:DIS: Port: 5565 [1728020685.780389][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020685.780409][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020685.780430][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020685.780450][50555:50557] CHIP:DIS: Vendor ID: 65521 [1728020685.780470][50555:50557] CHIP:DIS: Product ID: 32769 [1728020685.780489][50555:50557] CHIP:DIS: Long Discriminator: 22 [1728020685.780508][50555:50557] CHIP:DIS: Pairing Hint: 33 [1728020685.780527][50555:50557] CHIP:DIS: Instance Name: 5F4B1ED24E3EC2E7 [1728020685.780547][50555:50557] CHIP:DIS: Commissioning Mode: 1 [1728020685.780575][50555:50557] CHIP:CTL: Unknown filter type; all matches will fail [1728020685.781379][50555:50557] CHIP:DL: Avahi resolve found [1728020685.781442][50555:50557] CHIP:DIS: Discovered node: [1728020685.781461][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020685.781485][50555:50557] CHIP:DIS: IP Address #1: fe80::1 [1728020685.781505][50555:50557] CHIP:DIS: Port: 5565 [1728020685.781524][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020685.781543][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020685.781562][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020685.781582][50555:50557] CHIP:DIS: Vendor ID: 65521 [1728020685.781601][50555:50557] CHIP:DIS: Product ID: 32769 [1728020685.781620][50555:50557] CHIP:DIS: Long Discriminator: 22 [1728020685.781639][50555:50557] CHIP:DIS: Pairing Hint: 33 [1728020685.781658][50555:50557] CHIP:DIS: Instance Name: 5F4B1ED24E3EC2E7 [1728020685.781677][50555:50557] CHIP:DIS: Commissioning Mode: 1 [1728020685.781701][50555:50557] CHIP:CTL: Unknown filter type; all matches will fail [1728020685.782407][50555:50557] CHIP:EM: >>> [E:24002i S:0 M:181516366 (Ack:81919427)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) [1728020685.782444][50555:50557] CHIP:EM: Found matching exchange: 24002i, Delegate: 0xffff7c013800 [1728020685.782480][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:81919427 from Retrans Table on exchange 24002i [1728020685.782522][50555:50557] CHIP:SC: Received spake2p msg2 [1728020685.783965][50555:50557] CHIP:EM: <<< [E:24002i S:0 M:81919428 (Ack:181516366)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:24 (SecureChannel:PASE_Pake3) [1728020685.784165][50555:50557] CHIP:SC: Sent spake2p msg3 [1728020685.784272][50555:50557] CHIP:DL: Avahi resolve found [1728020685.784333][50555:50557] CHIP:DIS: Discovered node: [1728020685.784352][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020685.784375][50555:50557] CHIP:DIS: IP Address #1: fe80::42:3dff:fe6c:c020 [1728020685.784399][50555:50557] CHIP:DIS: Port: 5565 [1728020685.784421][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020685.784444][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020685.784467][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020685.784489][50555:50557] CHIP:DIS: Vendor ID: 65521 [1728020685.784584][50555:50557] CHIP:DIS: Product ID: 32769 [1728020685.784611][50555:50557] CHIP:DIS: Long Discriminator: 22 [1728020685.784635][50555:50557] CHIP:DIS: Pairing Hint: 33 [1728020685.784657][50555:50557] CHIP:DIS: Instance Name: 5F4B1ED24E3EC2E7 [1728020685.784679][50555:50557] CHIP:DIS: Commissioning Mode: 1 [1728020685.784711][50555:50557] CHIP:CTL: Unknown filter type; all matches will fail [1728020685.785768][50555:50557] CHIP:DL: Avahi resolve found [1728020685.785845][50555:50557] CHIP:DIS: Discovered node: [1728020685.785866][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020685.785893][50555:50557] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe69:4148 [1728020685.785913][50555:50557] CHIP:DIS: Port: 5565 [1728020685.785933][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020685.785952][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020685.785972][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020685.785992][50555:50557] CHIP:DIS: Vendor ID: 65521 [1728020685.786011][50555:50557] CHIP:DIS: Product ID: 32769 [1728020685.786030][50555:50557] CHIP:DIS: Long Discriminator: 22 [1728020685.786050][50555:50557] CHIP:DIS: Pairing Hint: 33 [1728020685.786069][50555:50557] CHIP:DIS: Instance Name: 5F4B1ED24E3EC2E7 [1728020685.786088][50555:50557] CHIP:DIS: Commissioning Mode: 1 [1728020685.786118][50555:50557] CHIP:CTL: Unknown filter type; all matches will fail [1728020685.787001][50555:50557] CHIP:EM: >>> [E:24002i S:0 M:181516367 (Ack:81919428)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) [1728020685.787050][50555:50557] CHIP:EM: Found matching exchange: 24002i, Delegate: 0xffff7c013800 [1728020685.787088][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:81919428 from Retrans Table on exchange 24002i [1728020685.787306][50555:50557] CHIP:SC: SecureSession[0xffff7c00ae70, LSID:25080]: State change 'kEstablishing' --> 'kActive' [1728020685.787340][50555:50557] CHIP:IN: SecureSession[0xffff7c00ae70]: Activated - Type:1 LSID:25080 [1728020685.787397][50555:50557] CHIP:IN: New secure session activated for device , LSID:25080 PSID:15596! [1728020685.787427][50555:50557] CHIP:CTL: Remote device completed SPAKE2+ handshake [1728020685.787446][50555:50557] CHIP:TOO: Pairing Success [1728020685.787463][50555:50557] CHIP:TOO: PASE establishment successful [1728020685.787484][50555:50557] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo' [1728020685.787511][50555:50557] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo' [1728020685.787530][50555:50557] CHIP:CTL: Sending request for commissioning information [1728020685.787569][50555:50557] CHIP:DMG: SendReadRequest ReadClient[0xffff7c00a0f0]: Sending Read Request [1728020685.787874][50555:50557] CHIP:EM: <<< [E:24003i S:25080 M:33558533] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:02 (IM:ReadRequest) [1728020685.788083][50555:50557] CHIP:DMG: MoveToState ReadClient[0xffff7c00a0f0]: Moving to [AwaitingIn] [1728020685.788199][50555:50557] CHIP:EM: <<< [E:24002i S:0 M:81919429 (Ack:181516367)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020685.788291][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:181516367 on exchange 24002i [1728020685.858459][50555:50557] CHIP:EM: >>> [E:24003i S:25080 M:115670337 (Ack:33558533)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) [1728020685.858497][50555:50557] CHIP:EM: Found matching exchange: 24003i, Delegate: 0xffff7c00a100 [1728020685.858533][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558533 from Retrans Table on exchange 24003i [1728020685.858617][50555:50557] CHIP:DMG: ReportDataMessage = [1728020685.858640][50555:50557] CHIP:DMG: { [1728020685.858657][50555:50557] CHIP:DMG: AttributeReportIBs = [1728020685.858682][50555:50557] CHIP:DMG: [ [1728020685.858701][50555:50557] CHIP:DMG: AttributeReportIB = [1728020685.858727][50555:50557] CHIP:DMG: { [1728020685.858748][50555:50557] CHIP:DMG: AttributeDataIB = [1728020685.858780][50555:50557] CHIP:DMG: { [1728020685.858806][50555:50557] CHIP:DMG: DataVersion = 0x3f6ad4cd, [1728020685.858829][50555:50557] CHIP:DMG: AttributePathIB = [1728020685.858854][50555:50557] CHIP:DMG: { [1728020685.858879][50555:50557] CHIP:DMG: Endpoint = 0x0, [1728020685.858905][50555:50557] CHIP:DMG: Cluster = 0x31, [1728020685.858931][50555:50557] CHIP:DMG: Attribute = 0x0000_0003, [1728020685.858956][50555:50557] CHIP:DMG: } [1728020685.858981][50555:50557] CHIP:DMG: [1728020685.859007][50555:50557] CHIP:DMG: Data = 0, [1728020685.859030][50555:50557] CHIP:DMG: }, [1728020685.859055][50555:50557] CHIP:DMG: [1728020685.859074][50555:50557] CHIP:DMG: }, [1728020685.859103][50555:50557] CHIP:DMG: [1728020685.859122][50555:50557] CHIP:DMG: AttributeReportIB = [1728020685.859147][50555:50557] CHIP:DMG: { [1728020685.859167][50555:50557] CHIP:DMG: AttributeDataIB = [1728020685.859189][50555:50557] CHIP:DMG: { [1728020685.859213][50555:50557] CHIP:DMG: DataVersion = 0x692a9e10, [1728020685.859237][50555:50557] CHIP:DMG: AttributePathIB = [1728020685.859260][50555:50557] CHIP:DMG: { [1728020685.859284][50555:50557] CHIP:DMG: Endpoint = 0x0, [1728020685.859310][50555:50557] CHIP:DMG: Cluster = 0x28, [1728020685.859335][50555:50557] CHIP:DMG: Attribute = 0x0000_0004, [1728020685.859398][50555:50557] CHIP:DMG: } [1728020685.859426][50555:50557] CHIP:DMG: [1728020685.859450][50555:50557] CHIP:DMG: Data = 32769, [1728020685.859478][50555:50557] CHIP:DMG: }, [1728020685.859506][50555:50557] CHIP:DMG: [1728020685.859525][50555:50557] CHIP:DMG: }, [1728020685.859552][50555:50557] CHIP:DMG: [1728020685.859573][50555:50557] CHIP:DMG: AttributeReportIB = [1728020685.859598][50555:50557] CHIP:DMG: { [1728020685.859617][50555:50557] CHIP:DMG: AttributeDataIB = [1728020685.859643][50555:50557] CHIP:DMG: { [1728020685.859669][50555:50557] CHIP:DMG: DataVersion = 0x692a9e10, [1728020685.859690][50555:50557] CHIP:DMG: AttributePathIB = [1728020685.859713][50555:50557] CHIP:DMG: { [1728020685.859739][50555:50557] CHIP:DMG: Endpoint = 0x0, [1728020685.859764][50555:50557] CHIP:DMG: Cluster = 0x28, [1728020685.859789][50555:50557] CHIP:DMG: Attribute = 0x0000_0002, [1728020685.859818][50555:50557] CHIP:DMG: } [1728020685.859845][50555:50557] CHIP:DMG: [1728020685.859871][50555:50557] CHIP:DMG: Data = 65521, [1728020685.859894][50555:50557] CHIP:DMG: }, [1728020685.859919][50555:50557] CHIP:DMG: [1728020685.859939][50555:50557] CHIP:DMG: }, [1728020685.859970][50555:50557] CHIP:DMG: [1728020685.859989][50555:50557] CHIP:DMG: AttributeReportIB = [1728020685.860014][50555:50557] CHIP:DMG: { [1728020685.860035][50555:50557] CHIP:DMG: AttributeDataIB = [1728020685.860057][50555:50557] CHIP:DMG: { [1728020685.860080][50555:50557] CHIP:DMG: DataVersion = 0xac8787cf, [1728020685.860104][50555:50557] CHIP:DMG: AttributePathIB = [1728020685.860128][50555:50557] CHIP:DMG: { [1728020685.860153][50555:50557] CHIP:DMG: Endpoint = 0x0, [1728020685.860179][50555:50557] CHIP:DMG: Cluster = 0x30, [1728020685.860205][50555:50557] CHIP:DMG: Attribute = 0x0000_0003, [1728020685.860229][50555:50557] CHIP:DMG: } [1728020685.860254][50555:50557] CHIP:DMG: [1728020685.860279][50555:50557] CHIP:DMG: Data = 2, [1728020685.860302][50555:50557] CHIP:DMG: }, [1728020685.860326][50555:50557] CHIP:DMG: [1728020685.860346][50555:50557] CHIP:DMG: }, [1728020685.860374][50555:50557] CHIP:DMG: [1728020685.860393][50555:50557] CHIP:DMG: AttributeReportIB = [1728020685.860417][50555:50557] CHIP:DMG: { [1728020685.860438][50555:50557] CHIP:DMG: AttributeDataIB = [1728020685.860460][50555:50557] CHIP:DMG: { [1728020685.860483][50555:50557] CHIP:DMG: DataVersion = 0xac8787cf, [1728020685.860506][50555:50557] CHIP:DMG: AttributePathIB = [1728020685.860530][50555:50557] CHIP:DMG: { [1728020685.860554][50555:50557] CHIP:DMG: Endpoint = 0x0, [1728020685.860580][50555:50557] CHIP:DMG: Cluster = 0x30, [1728020685.860606][50555:50557] CHIP:DMG: Attribute = 0x0000_0002, [1728020685.860631][50555:50557] CHIP:DMG: } [1728020685.860656][50555:50557] CHIP:DMG: [1728020685.860682][50555:50557] CHIP:DMG: Data = 0, [1728020685.860704][50555:50557] CHIP:DMG: }, [1728020685.860729][50555:50557] CHIP:DMG: [1728020685.860750][50555:50557] CHIP:DMG: }, [1728020685.860780][50555:50557] CHIP:DMG: [1728020685.860800][50555:50557] CHIP:DMG: AttributeReportIB = [1728020685.860826][50555:50557] CHIP:DMG: { [1728020685.860847][50555:50557] CHIP:DMG: AttributeDataIB = [1728020685.860869][50555:50557] CHIP:DMG: { [1728020685.860892][50555:50557] CHIP:DMG: DataVersion = 0xac8787cf, [1728020685.860915][50555:50557] CHIP:DMG: AttributePathIB = [1728020685.860939][50555:50557] CHIP:DMG: { [1728020685.860963][50555:50557] CHIP:DMG: Endpoint = 0x0, [1728020685.860989][50555:50557] CHIP:DMG: Cluster = 0x30, [1728020685.861015][50555:50557] CHIP:DMG: Attribute = 0x0000_0001, [1728020685.861040][50555:50557] CHIP:DMG: } [1728020685.861065][50555:50557] CHIP:DMG: [1728020685.861088][50555:50557] CHIP:DMG: Data = [1728020685.861113][50555:50557] CHIP:DMG: { [1728020685.861138][50555:50557] CHIP:DMG: 0x0 = 60, [1728020685.861165][50555:50557] CHIP:DMG: 0x1 = 900, [1728020685.861190][50555:50557] CHIP:DMG: }, [1728020685.861213][50555:50557] CHIP:DMG: }, [1728020685.861239][50555:50557] CHIP:DMG: [1728020685.861259][50555:50557] CHIP:DMG: }, [1728020685.861289][50555:50557] CHIP:DMG: [1728020685.861308][50555:50557] CHIP:DMG: AttributeReportIB = [1728020685.861333][50555:50557] CHIP:DMG: { [1728020685.861353][50555:50557] CHIP:DMG: AttributeDataIB = [1728020685.861373][50555:50557] CHIP:DMG: { [1728020685.861396][50555:50557] CHIP:DMG: DataVersion = 0xac8787cf, [1728020685.861419][50555:50557] CHIP:DMG: AttributePathIB = [1728020685.861442][50555:50557] CHIP:DMG: { [1728020685.861467][50555:50557] CHIP:DMG: Endpoint = 0x0, [1728020685.861493][50555:50557] CHIP:DMG: Cluster = 0x30, [1728020685.861519][50555:50557] CHIP:DMG: Attribute = 0x0000_0000, [1728020685.861543][50555:50557] CHIP:DMG: } [1728020685.861568][50555:50557] CHIP:DMG: [1728020685.861594][50555:50557] CHIP:DMG: Data = 0, [1728020685.861616][50555:50557] CHIP:DMG: }, [1728020685.861641][50555:50557] CHIP:DMG: [1728020685.861660][50555:50557] CHIP:DMG: }, [1728020685.861689][50555:50557] CHIP:DMG: [1728020685.861708][50555:50557] CHIP:DMG: AttributeReportIB = [1728020685.861733][50555:50557] CHIP:DMG: { [1728020685.861754][50555:50557] CHIP:DMG: AttributeDataIB = [1728020685.861776][50555:50557] CHIP:DMG: { [1728020685.861800][50555:50557] CHIP:DMG: DataVersion = 0x3f6ad4cd, [1728020685.861823][50555:50557] CHIP:DMG: AttributePathIB = [1728020685.861846][50555:50557] CHIP:DMG: { [1728020685.861871][50555:50557] CHIP:DMG: Endpoint = 0x0, [1728020685.861897][50555:50557] CHIP:DMG: Cluster = 0x31, [1728020685.861923][50555:50557] CHIP:DMG: Attribute = 0x0000_FFFC, [1728020685.861948][50555:50557] CHIP:DMG: } [1728020685.861973][50555:50557] CHIP:DMG: [1728020685.861998][50555:50557] CHIP:DMG: Data = 4, [1728020685.862021][50555:50557] CHIP:DMG: }, [1728020685.862046][50555:50557] CHIP:DMG: [1728020685.862065][50555:50557] CHIP:DMG: }, [1728020685.862089][50555:50557] CHIP:DMG: [1728020685.862107][50555:50557] CHIP:DMG: ], [1728020685.862155][50555:50557] CHIP:DMG: [1728020685.862175][50555:50557] CHIP:DMG: SuppressResponse = true, [1728020685.862195][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020685.862213][50555:50557] CHIP:DMG: } [1728020685.862942][50555:50557] CHIP:CTL: ----- NetworkCommissioning Features: has Ethernet. endpointid = 0 [1728020685.863030][50555:50557] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo' [1728020685.863057][50555:50557] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe' [1728020685.863093][50555:50557] CHIP:CTL: Performing next commissioning step 'ArmFailSafe' [1728020685.863113][50555:50557] CHIP:CTL: Arming failsafe (60 seconds) [1728020685.863173][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020685.863200][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020685.863439][50555:50557] CHIP:EM: <<< [E:24004i S:25080 M:33558534] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020685.863636][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020685.863783][50555:50557] CHIP:EM: <<< [E:24003i S:25080 M:33558535 (Ack:115670337)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020685.863873][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670337 on exchange 24003i [1728020685.873689][50555:50557] CHIP:EM: >>> [E:24004i S:25080 M:115670338 (Ack:33558534)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020685.873727][50555:50557] CHIP:EM: Found matching exchange: 24004i, Delegate: 0xffff7c00a0f8 [1728020685.873764][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558534 from Retrans Table on exchange 24004i [1728020685.873797][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020685.873841][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020685.873860][50555:50557] CHIP:DMG: { [1728020685.873879][50555:50557] CHIP:DMG: suppressResponse = false, [1728020685.873898][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020685.873923][50555:50557] CHIP:DMG: [ [1728020685.873942][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020685.873968][50555:50557] CHIP:DMG: { [1728020685.873988][50555:50557] CHIP:DMG: CommandDataIB = [1728020685.874019][50555:50557] CHIP:DMG: { [1728020685.874044][50555:50557] CHIP:DMG: CommandPathIB = [1728020685.874073][50555:50557] CHIP:DMG: { [1728020685.874101][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020685.874131][50555:50557] CHIP:DMG: ClusterId = 0x30, [1728020685.874159][50555:50557] CHIP:DMG: CommandId = 0x1, [1728020685.874186][50555:50557] CHIP:DMG: }, [1728020685.874214][50555:50557] CHIP:DMG: [1728020685.874240][50555:50557] CHIP:DMG: CommandFields = [1728020685.874267][50555:50557] CHIP:DMG: { [1728020685.874386][50555:50557] CHIP:DMG: 0x0 = 0, [1728020685.874417][50555:50557] CHIP:DMG: 0x1 = "" (0 chars), [1728020685.874446][50555:50557] CHIP:DMG: }, [1728020685.874472][50555:50557] CHIP:DMG: }, [1728020685.874502][50555:50557] CHIP:DMG: [1728020685.874525][50555:50557] CHIP:DMG: }, [1728020685.874550][50555:50557] CHIP:DMG: [1728020685.874568][50555:50557] CHIP:DMG: ], [1728020685.874594][50555:50557] CHIP:DMG: [1728020685.874613][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020685.874635][50555:50557] CHIP:DMG: }, [1728020685.874689][50555:50557] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001 [1728020685.874749][50555:50557] CHIP:CTL: Received ArmFailSafe response errorCode=0 [1728020685.874780][50555:50557] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe' [1728020685.874799][50555:50557] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory' [1728020685.874832][50555:50557] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory' [1728020685.874850][50555:50557] CHIP:CTL: Setting Regulatory Config [1728020685.874867][50555:50557] CHIP:CTL: No regulatory config supplied by controller, leaving as device default (0) [1728020685.874930][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020685.874973][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020685.875186][50555:50557] CHIP:EM: <<< [E:24005i S:25080 M:33558536] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020685.875475][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020685.875542][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020685.875708][50555:50557] CHIP:EM: <<< [E:24004i S:25080 M:33558537 (Ack:115670338)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020685.875818][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670338 on exchange 24004i [1728020685.879036][50555:50557] CHIP:EM: >>> [E:24005i S:25080 M:115670339 (Ack:33558536)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020685.879073][50555:50557] CHIP:EM: Found matching exchange: 24005i, Delegate: 0xffff7c008f68 [1728020685.879108][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558536 from Retrans Table on exchange 24005i [1728020685.879140][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020685.879183][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020685.879203][50555:50557] CHIP:DMG: { [1728020685.879222][50555:50557] CHIP:DMG: suppressResponse = false, [1728020685.879240][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020685.879264][50555:50557] CHIP:DMG: [ [1728020685.879282][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020685.879306][50555:50557] CHIP:DMG: { [1728020685.879349][50555:50557] CHIP:DMG: CommandDataIB = [1728020685.879438][50555:50557] CHIP:DMG: { [1728020685.879466][50555:50557] CHIP:DMG: CommandPathIB = [1728020685.879511][50555:50557] CHIP:DMG: { [1728020685.879559][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020685.879608][50555:50557] CHIP:DMG: ClusterId = 0x30, [1728020685.879655][50555:50557] CHIP:DMG: CommandId = 0x3, [1728020685.879700][50555:50557] CHIP:DMG: }, [1728020685.879749][50555:50557] CHIP:DMG: [1728020685.879775][50555:50557] CHIP:DMG: CommandFields = [1728020685.879818][50555:50557] CHIP:DMG: { [1728020685.879867][50555:50557] CHIP:DMG: 0x0 = 0, [1728020685.879917][50555:50557] CHIP:DMG: 0x1 = "" (0 chars), [1728020685.879965][50555:50557] CHIP:DMG: }, [1728020685.880008][50555:50557] CHIP:DMG: }, [1728020685.880039][50555:50557] CHIP:DMG: [1728020685.880081][50555:50557] CHIP:DMG: }, [1728020685.880107][50555:50557] CHIP:DMG: [1728020685.880126][50555:50557] CHIP:DMG: ], [1728020685.880151][50555:50557] CHIP:DMG: [1728020685.880171][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020685.880189][50555:50557] CHIP:DMG: }, [1728020685.880242][50555:50557] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003 [1728020685.880274][50555:50557] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0 [1728020685.880303][50555:50557] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory' [1728020685.880322][50555:50557] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest' [1728020685.880355][50555:50557] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest' [1728020685.880372][50555:50557] CHIP:CTL: Sending request for PAI certificate [1728020685.880389][50555:50557] CHIP:CTL: Sending Certificate Chain request to 0xffff7c0137b0 device [1728020685.880450][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020685.880498][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020685.880704][50555:50557] CHIP:EM: <<< [E:24006i S:25080 M:33558538] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020685.880882][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020685.880938][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020685.881065][50555:50557] CHIP:EM: <<< [E:24005i S:25080 M:33558539 (Ack:115670339)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020685.881148][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670339 on exchange 24005i [1728020685.882861][50555:50557] CHIP:EM: >>> [E:24006i S:25080 M:115670340 (Ack:33558538)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020685.882890][50555:50557] CHIP:EM: Found matching exchange: 24006i, Delegate: 0xffff7c00a0f8 [1728020685.882924][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558538 from Retrans Table on exchange 24006i [1728020685.882956][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020685.882998][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020685.883017][50555:50557] CHIP:DMG: { [1728020685.883036][50555:50557] CHIP:DMG: suppressResponse = false, [1728020685.883055][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020685.883079][50555:50557] CHIP:DMG: [ [1728020685.883285][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020685.883318][50555:50557] CHIP:DMG: { [1728020685.883339][50555:50557] CHIP:DMG: CommandDataIB = [1728020685.883431][50555:50557] CHIP:DMG: { [1728020685.883459][50555:50557] CHIP:DMG: CommandPathIB = [1728020685.883505][50555:50557] CHIP:DMG: { [1728020685.883535][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020685.883580][50555:50557] CHIP:DMG: ClusterId = 0x3e, [1728020685.883626][50555:50557] CHIP:DMG: CommandId = 0x3, [1728020685.883671][50555:50557] CHIP:DMG: }, [1728020685.883702][50555:50557] CHIP:DMG: [1728020685.883741][50555:50557] CHIP:DMG: CommandFields = [1728020685.883772][50555:50557] CHIP:DMG: { [1728020685.883816][50555:50557] CHIP:DMG: 0x0 = [ [1728020685.883947][50555:50557] CHIP:DMG: 0x30, 0x82, 0x01, 0xcb, 0x30, 0x82, 0x01, 0x71, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x56, 0xad, 0x82, 0x22, 0xad, 0x94, 0x5b, 0x64, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x30, 0x31, 0x18, 0x30, 0x16, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x0f, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x54, 0x65, 0x73, 0x74, 0x20, 0x50, 0x41, 0x41, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 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, 0x41, 0x9a, 0x93, 0x15, 0xc2, 0x17, 0x3e, 0x0c, 0x8c, 0x87, 0x6d, 0x03, 0xcc, 0xfc, 0x94, 0x48, 0x52, 0x64, 0x7f, 0x7f, 0xec, 0x5e, 0x50, 0x82, 0xf4, 0x05, 0x99, 0x28, 0xec, 0xa8, 0x94, 0xc5, 0x94, 0x15, 0x13, 0x09, 0xac, 0x63, 0x1e, 0x4c, 0xb0, 0x33, 0x92, 0xaf, 0x68, 0x4b, 0x0b, 0xaf, 0xb7, 0xe6, 0x5b, 0x3b, 0x81, 0x62, 0xc2, 0xf5, 0x2b, 0xf9, 0x31, 0xb8, 0xe7, 0x7a, 0xaa, 0x82, 0xa3, 0x66, 0x30, 0x64, 0x30, 0x12, 0x06, 0x03, 0x55, 0x1d, 0x [1728020685.884009][50555:50557] CHIP:DMG: ] (463 bytes) [1728020685.884040][50555:50557] CHIP:DMG: }, [1728020685.884069][50555:50557] CHIP:DMG: }, [1728020685.884099][50555:50557] CHIP:DMG: [1728020685.884121][50555:50557] CHIP:DMG: }, [1728020685.884145][50555:50557] CHIP:DMG: [1728020685.884164][50555:50557] CHIP:DMG: ], [1728020685.884189][50555:50557] CHIP:DMG: [1728020685.884209][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020685.884227][50555:50557] CHIP:DMG: }, [1728020685.884280][50555:50557] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1728020685.884312][50555:50557] CHIP:CTL: Received certificate chain from the device [1728020685.884341][50555:50557] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest' [1728020685.884364][50555:50557] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest' [1728020685.884398][50555:50557] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest' [1728020685.884416][50555:50557] CHIP:CTL: Sending request for DAC certificate [1728020685.884432][50555:50557] CHIP:CTL: Sending Certificate Chain request to 0xffff7c0137b0 device [1728020685.884493][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020685.884519][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020685.884713][50555:50557] CHIP:EM: <<< [E:24007i S:25080 M:33558540] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020685.884892][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020685.884949][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020685.885073][50555:50557] CHIP:EM: <<< [E:24006i S:25080 M:33558541 (Ack:115670340)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020685.885163][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670340 on exchange 24006i [1728020685.974970][50555:50557] CHIP:EM: >>> [E:24007i S:25080 M:115670341 (Ack:33558540)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020685.975006][50555:50557] CHIP:EM: Found matching exchange: 24007i, Delegate: 0xffff7c008f68 [1728020685.975043][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558540 from Retrans Table on exchange 24007i [1728020685.975075][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020685.975120][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020685.975139][50555:50557] CHIP:DMG: { [1728020685.975158][50555:50557] CHIP:DMG: suppressResponse = false, [1728020685.975177][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020685.975202][50555:50557] CHIP:DMG: [ [1728020685.975221][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020685.975247][50555:50557] CHIP:DMG: { [1728020685.975267][50555:50557] CHIP:DMG: CommandDataIB = [1728020685.975315][50555:50557] CHIP:DMG: { [1728020685.975340][50555:50557] CHIP:DMG: CommandPathIB = [1728020685.975395][50555:50557] CHIP:DMG: { [1728020685.975429][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020685.975460][50555:50557] CHIP:DMG: ClusterId = 0x3e, [1728020685.975488][50555:50557] CHIP:DMG: CommandId = 0x3, [1728020685.975516][50555:50557] CHIP:DMG: }, [1728020685.975545][50555:50557] CHIP:DMG: [1728020685.975570][50555:50557] CHIP:DMG: CommandFields = [1728020685.975598][50555:50557] CHIP:DMG: { [1728020685.975627][50555:50557] CHIP:DMG: 0x0 = [ [1728020685.975741][50555:50557] CHIP:DMG: 0x30, 0x82, 0x01, 0xe7, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x69, 0xcd, 0xf1, 0x0d, 0xe9, 0xe5, 0x4e, 0xd1, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x53, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x44, 0x41, 0x43, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x2f, 0x30, 0x78, 0x38, 0x30, 0x30, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x02, 0x0c, 0x04, 0x38, 0x30, 0x30, 0x31, 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, 0x46, 0x3a, 0xc6, 0x93, 0x42, 0x91, 0x0a, 0x0e, 0x55, 0x88, 0xfc, 0x6f, 0xf5, 0x6b, 0xb6, 0x3e, 0x62, 0xec, 0xce, 0xcb, 0x14, 0x8f, 0x7d, 0x4e, 0xb0, 0x3e, 0xe5, 0x52, 0x60, 0x14, 0x15, 0x76, 0x7d, 0x16, 0xa5, 0xc6, 0x63, 0xf7, 0x93, 0x [1728020685.975802][50555:50557] CHIP:DMG: ] (491 bytes) [1728020685.975831][50555:50557] CHIP:DMG: }, [1728020685.975857][50555:50557] CHIP:DMG: }, [1728020685.975886][50555:50557] CHIP:DMG: [1728020685.975906][50555:50557] CHIP:DMG: }, [1728020685.975931][50555:50557] CHIP:DMG: [1728020685.975950][50555:50557] CHIP:DMG: ], [1728020685.975975][50555:50557] CHIP:DMG: [1728020685.975995][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020685.976013][50555:50557] CHIP:DMG: }, [1728020685.976066][50555:50557] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1728020685.976095][50555:50557] CHIP:CTL: Received certificate chain from the device [1728020685.976124][50555:50557] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest' [1728020685.976148][50555:50557] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest' [1728020685.976181][50555:50557] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest' [1728020685.976199][50555:50557] CHIP:CTL: Sending Attestation Request to the device. [1728020685.976217][50555:50557] CHIP:CTL: Sending Attestation request to 0xffff7c0137b0 device [1728020685.976281][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020685.976310][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020685.976526][50555:50557] CHIP:EM: <<< [E:24008i S:25080 M:33558542] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020685.976714][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020685.976748][50555:50557] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information [1728020685.976794][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020685.976932][50555:50557] CHIP:EM: <<< [E:24007i S:25080 M:33558543 (Ack:115670341)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020685.977035][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670341 on exchange 24007i [1728020685.987082][50555:50557] CHIP:EM: >>> [E:24008i S:25080 M:115670342 (Ack:33558542)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020685.987116][50555:50557] CHIP:EM: Found matching exchange: 24008i, Delegate: 0xffff7c00a0f8 [1728020685.987151][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558542 from Retrans Table on exchange 24008i [1728020685.988072][50555:50557] CHIP:EM: >>> [E:24008i S:25080 M:115670343 (Ack:33558542)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020685.988104][50555:50557] CHIP:EM: Found matching exchange: 24008i, Delegate: 0xffff7c00a0f8 [1728020685.988125][50555:50557] CHIP:EM: CHIP MessageCounter:33558542 not in RetransTable on exchange 24008i [1728020685.988160][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020685.988204][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020685.988223][50555:50557] CHIP:DMG: { [1728020685.988241][50555:50557] CHIP:DMG: suppressResponse = false, [1728020685.988260][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020685.988286][50555:50557] CHIP:DMG: [ [1728020685.988305][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020685.988332][50555:50557] CHIP:DMG: { [1728020685.988352][50555:50557] CHIP:DMG: CommandDataIB = [1728020685.988402][50555:50557] CHIP:DMG: { [1728020685.988428][50555:50557] CHIP:DMG: CommandPathIB = [1728020685.988456][50555:50557] CHIP:DMG: { [1728020685.988485][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020685.988515][50555:50557] CHIP:DMG: ClusterId = 0x3e, [1728020685.988543][50555:50557] CHIP:DMG: CommandId = 0x1, [1728020685.988570][50555:50557] CHIP:DMG: }, [1728020685.988598][50555:50557] CHIP:DMG: [1728020685.988623][50555:50557] CHIP:DMG: CommandFields = [1728020685.988651][50555:50557] CHIP:DMG: { [1728020685.988680][50555:50557] CHIP:DMG: 0x0 = [ [1728020685.988797][50555:50557] CHIP:DMG: 0x15, 0x31, 0x01, 0x1b, 0x02, 0x30, 0x82, 0x02, 0x17, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x82, 0x02, 0x08, 0x30, 0x82, 0x02, 0x04, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x82, 0x01, 0x70, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x82, 0x01, 0x61, 0x04, 0x82, 0x01, 0x5d, 0x15, 0x24, 0x00, 0x01, 0x25, 0x01, 0xf1, 0xff, 0x36, 0x02, 0x05, 0x00, 0x80, 0x05, 0x01, 0x80, 0x05, 0x02, 0x80, 0x05, 0x03, 0x80, 0x05, 0x04, 0x80, 0x05, 0x05, 0x80, 0x05, 0x06, 0x80, 0x05, 0x07, 0x80, 0x05, 0x08, 0x80, 0x05, 0x09, 0x80, 0x05, 0x0a, 0x80, 0x05, 0x0b, 0x80, 0x05, 0x0c, 0x80, 0x05, 0x0d, 0x80, 0x05, 0x0e, 0x80, 0x05, 0x0f, 0x80, 0x05, 0x10, 0x80, 0x05, 0x11, 0x80, 0x05, 0x12, 0x80, 0x05, 0x13, 0x80, 0x05, 0x14, 0x80, 0x05, 0x15, 0x80, 0x05, 0x16, 0x80, 0x05, 0x17, 0x80, 0x05, 0x18, 0x80, 0x05, 0x19, 0x80, 0x05, 0x1a, 0x80, 0x05, 0x1b, 0x80, 0x05, 0x1c, 0x80, 0x05, 0x1d, 0x80, 0x05, 0x1e, 0x80, 0x05, 0x1f, 0x80, 0x05, 0x20, 0x80, 0x05, 0x21, 0x80, 0x05, 0x22, 0x80, 0x05, 0x23, 0x80, 0x05, 0x24, 0x80, 0x05, 0x25, 0x80, 0x05, 0x26, 0x80, 0x05, 0x27, 0x80, 0x05, 0x28, 0x80, 0x05, 0x29, 0x80, 0x05, 0x2a, 0x80, 0x05, 0x2b, 0x80, 0x05, 0x2c, 0x80, 0x05, 0x2d, 0x80, 0x05, 0x2e, 0x80, 0x05, 0x2f, 0x80, 0x05, 0x30, 0x80, 0x05, 0x31, 0x80, 0x05, 0x32, 0x80, 0x05, 0x33, 0x80, 0x05, 0x34, 0x80, 0x05, 0x35, 0x80, 0x05, 0x36, 0x80, 0x05, 0x37, 0x80, 0x05, 0x38, 0x80, 0x05, 0x39, 0x80, 0x05, 0x3a, 0x80, 0x05, 0x3b, 0x80, 0x05, 0x3c, 0x80, 0x05, 0x3d, 0x80, 0x05, 0x3e, 0x80, 0x05, 0x3f, 0x80, 0x05, 0x40, 0x80, 0x05, 0x41, 0x80, 0x05, 0x42, 0x80, 0x05, 0x43, 0x80, 0x [1728020685.988856][50555:50557] CHIP:DMG: ] (583 bytes) [1728020685.988887][50555:50557] CHIP:DMG: 0x1 = [ [1728020685.988929][50555:50557] CHIP:DMG: 0x94, 0x00, 0xed, 0xf3, 0xa1, 0x70, 0x12, 0xb9, 0x0c, 0x3c, 0xdf, 0xf1, 0x97, 0x10, 0xc6, 0xae, 0x59, 0xb3, 0x82, 0x13, 0x8e, 0x29, 0x2b, 0x8c, 0xa3, 0x75, 0x49, 0x13, 0xec, 0xf2, 0x9f, 0xe6, 0x2d, 0x08, 0x13, 0x49, 0x84, 0x2a, 0x5b, 0x11, 0x4f, 0x67, 0x1f, 0x6f, 0x55, 0xf9, 0x0f, 0xd3, 0x1e, 0x2e, 0xdd, 0x78, 0x57, 0x60, 0x52, 0x6f, 0xdd, 0xd3, 0xb0, 0x80, 0xd4, 0x25, 0x8a, 0xf0, [1728020685.988967][50555:50557] CHIP:DMG: ] (64 bytes) [1728020685.988998][50555:50557] CHIP:DMG: }, [1728020685.989025][50555:50557] CHIP:DMG: }, [1728020685.989054][50555:50557] CHIP:DMG: [1728020685.989075][50555:50557] CHIP:DMG: }, [1728020685.989100][50555:50557] CHIP:DMG: [1728020685.989118][50555:50557] CHIP:DMG: ], [1728020685.989143][50555:50557] CHIP:DMG: [1728020685.989162][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020685.989180][50555:50557] CHIP:DMG: }, [1728020685.989235][50555:50557] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001 [1728020685.989267][50555:50557] CHIP:CTL: Received Attestation Information from the device [1728020685.989295][50555:50557] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest' [1728020685.989316][50555:50557] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 583/583 [1728020685.989359][50555:50557] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification' [1728020685.989392][50555:50557] CHIP:CTL: Performing next commissioning step 'AttestationVerification' [1728020685.989410][50555:50557] CHIP:CTL: Verifying attestation [1728020686.013964][50555:50557] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device. [1728020686.014038][50555:50557] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification' [1728020686.014057][50555:50557] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest' [1728020686.014100][50555:50557] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest' [1728020686.014123][50555:50557] CHIP:CTL: Sending CSR request to 0xffff7c0137b0 device [1728020686.014197][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020686.014228][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020686.014486][50555:50557] CHIP:EM: <<< [E:24009i S:25080 M:33558544] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020686.014681][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020686.014717][50555:50557] CHIP:CTL: Sent CSR request, waiting for the CSR [1728020686.014773][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020686.014927][50555:50557] CHIP:EM: <<< [E:24008i S:25080 M:33558545 (Ack:115670343)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.015027][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670343 on exchange 24008i [1728020686.081701][50555:50557] CHIP:EM: >>> [E:24009i S:25080 M:115670344 (Ack:33558544)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.081751][50555:50557] CHIP:EM: Found matching exchange: 24009i, Delegate: 0xffff7c024548 [1728020686.081790][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558544 from Retrans Table on exchange 24009i [1728020686.083746][50555:50557] CHIP:EM: >>> [E:24009i S:25080 M:115670345 (Ack:33558544)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020686.083780][50555:50557] CHIP:EM: Found matching exchange: 24009i, Delegate: 0xffff7c024548 [1728020686.083803][50555:50557] CHIP:EM: CHIP MessageCounter:33558544 not in RetransTable on exchange 24009i [1728020686.083840][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020686.083887][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020686.083907][50555:50557] CHIP:DMG: { [1728020686.083924][50555:50557] CHIP:DMG: suppressResponse = false, [1728020686.083946][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020686.083971][50555:50557] CHIP:DMG: [ [1728020686.083991][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020686.084018][50555:50557] CHIP:DMG: { [1728020686.084038][50555:50557] CHIP:DMG: CommandDataIB = [1728020686.084063][50555:50557] CHIP:DMG: { [1728020686.084086][50555:50557] CHIP:DMG: CommandPathIB = [1728020686.084112][50555:50557] CHIP:DMG: { [1728020686.084137][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020686.084167][50555:50557] CHIP:DMG: ClusterId = 0x3e, [1728020686.084194][50555:50557] CHIP:DMG: CommandId = 0x5, [1728020686.084217][50555:50557] CHIP:DMG: }, [1728020686.084244][50555:50557] CHIP:DMG: [1728020686.084267][50555:50557] CHIP:DMG: CommandFields = [1728020686.084292][50555:50557] CHIP:DMG: { [1728020686.084318][50555:50557] CHIP:DMG: 0x0 = [ [1728020686.084413][50555:50557] CHIP:DMG: 0x15, 0x30, 0x01, 0xcc, 0x30, 0x81, 0xc9, 0x30, 0x70, 0x02, 0x01, 0x00, 0x30, 0x0e, 0x31, 0x0c, 0x30, 0x0a, 0x06, 0x03, 0x55, 0x04, 0x0a, 0x0c, 0x03, 0x43, 0x53, 0x52, 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, 0x13, 0xfb, 0x97, 0xda, 0xbd, 0x99, 0x4e, 0x01, 0xde, 0x95, 0x06, 0x93, 0x16, 0x4d, 0x66, 0xa4, 0xd0, 0x08, 0x8a, 0xc0, 0x55, 0xd7, 0x23, 0x7d, 0x73, 0x5f, 0x8e, 0x38, 0x12, 0xb7, 0x0c, 0x54, 0x3e, 0x38, 0xf2, 0x3f, 0xf6, 0x54, 0x73, 0xdd, 0x3a, 0x51, 0x7a, 0x50, 0xa2, 0x2d, 0x2e, 0x45, 0x13, 0x59, 0x2a, 0x35, 0x65, 0xa1, 0x3f, 0xe8, 0xd6, 0xdd, 0x27, 0x89, 0xb7, 0xe0, 0x8b, 0x3a, 0xa0, 0x00, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x03, 0x49, 0x00, 0x30, 0x46, 0x02, 0x21, 0x00, 0xb2, 0x05, 0x3d, 0xe1, 0x0a, 0xff, 0x20, 0xf4, 0x5b, 0xa8, 0x70, 0xfc, 0xf5, 0x22, 0xd8, 0xab, 0x27, 0xea, 0x73, 0xc5, 0x77, 0x90, 0x9b, 0xbf, 0xca, 0xaa, 0x29, 0x8a, 0xee, 0x3a, 0xf6, 0xb1, 0x02, 0x21, 0x00, 0xd5, 0x9e, 0x79, 0xae, 0x85, 0x97, 0xba, 0x62, 0x24, 0xea, 0x01, 0x72, 0xc6, 0xd3, 0x0d, 0xb6, 0x70, 0xa8, 0xd9, 0x2f, 0x9c, 0x5a, 0x0d, 0x56, 0x17, 0x0b, 0x61, 0x34, 0xec, 0xa1, 0x08, 0xa4, 0x30, 0x02, 0x20, 0x96, 0x08, 0x48, 0x9e, 0xec, 0x63, 0x46, 0x43, 0x78, 0x72, 0x10, 0x5b, 0x0f, 0xb0, 0x98, 0x02, 0x41, 0x60, 0x58, 0x15, 0x54, 0xb1, 0x67, 0x17, 0x98, 0x78, 0x7c, 0x23, 0xd0, 0xb9, 0xcf, 0x09, 0x18, [1728020686.084467][50555:50557] CHIP:DMG: ] (244 bytes) [1728020686.084493][50555:50557] CHIP:DMG: 0x1 = [ [1728020686.084536][50555:50557] CHIP:DMG: 0x32, 0x54, 0x27, 0xb1, 0x93, 0xb8, 0xf8, 0x24, 0x25, 0xb4, 0x72, 0x47, 0xe5, 0x02, 0xd8, 0xeb, 0x64, 0x2b, 0xe8, 0xaf, 0xc5, 0x8c, 0x21, 0x50, 0xb7, 0xad, 0xbb, 0x29, 0xf3, 0xf1, 0x54, 0x29, 0x9a, 0xe8, 0xa0, 0xc3, 0xa5, 0xfb, 0x7e, 0x16, 0x0d, 0x5a, 0xeb, 0x73, 0x1e, 0xde, 0x06, 0xe3, 0x75, 0xde, 0xf0, 0x9e, 0xa2, 0xc8, 0x0a, 0x8b, 0x5c, 0xdd, 0x18, 0xee, 0x10, 0xd7, 0x21, 0x99, [1728020686.084569][50555:50557] CHIP:DMG: ] (64 bytes) [1728020686.084596][50555:50557] CHIP:DMG: }, [1728020686.084620][50555:50557] CHIP:DMG: }, [1728020686.084646][50555:50557] CHIP:DMG: [1728020686.084667][50555:50557] CHIP:DMG: }, [1728020686.084692][50555:50557] CHIP:DMG: [1728020686.084710][50555:50557] CHIP:DMG: ], [1728020686.084736][50555:50557] CHIP:DMG: [1728020686.084755][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020686.084774][50555:50557] CHIP:DMG: }, [1728020686.084828][50555:50557] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005 [1728020686.084861][50555:50557] CHIP:CTL: Received certificate signing request from the device [1728020686.084889][50555:50557] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest' [1728020686.084909][50555:50557] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR' [1728020686.084940][50555:50557] CHIP:CTL: Performing next commissioning step 'ValidateCSR' [1728020686.088032][50555:50557] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR' [1728020686.088089][50555:50557] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain' [1728020686.088123][50555:50557] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain' [1728020686.088146][50555:50557] CHIP:CTL: Getting certificate chain for the device from the issuer [1728020686.091004][50555:50557] CHIP:CTL: Verifying Certificate Signing Request [1728020686.093175][50555:50557] CHIP:CTL: Generating NOC [1728020686.093535][50555:50557] CHIP:CTL: Providing certificate chain to the commissioner [1728020686.093572][50555:50557] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status src/controller/ExampleOperationalCredentialsIssuer.cpp:396: Success [1728020686.093607][50555:50557] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain' [1728020686.093788][50555:50557] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert' [1728020686.093817][50555:50557] CHIP:CTL: Sending root certificate to the device [1728020686.093895][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020686.093927][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020686.094174][50555:50557] CHIP:EM: <<< [E:24010i S:25080 M:33558546] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020686.094377][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020686.094416][50555:50557] CHIP:CTL: Sent root certificate to the device [1728020686.094923][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020686.095136][50555:50557] CHIP:EM: <<< [E:24009i S:25080 M:33558547 (Ack:115670345)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.095277][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670345 on exchange 24009i [1728020686.096447][50555:50557] CHIP:EM: >>> [E:24010i S:25080 M:115670346 (Ack:33558546)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.096484][50555:50557] CHIP:EM: Found matching exchange: 24010i, Delegate: 0xffff7c00a0f8 [1728020686.096524][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558546 from Retrans Table on exchange 24010i [1728020686.098070][50555:50557] CHIP:EM: >>> [E:24010i S:25080 M:115670347 (Ack:33558546)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020686.098115][50555:50557] CHIP:EM: Found matching exchange: 24010i, Delegate: 0xffff7c00a0f8 [1728020686.098147][50555:50557] CHIP:EM: CHIP MessageCounter:33558546 not in RetransTable on exchange 24010i [1728020686.098196][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020686.098252][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020686.098278][50555:50557] CHIP:DMG: { [1728020686.098301][50555:50557] CHIP:DMG: suppressResponse = false, [1728020686.098326][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020686.098357][50555:50557] CHIP:DMG: [ [1728020686.098382][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020686.098418][50555:50557] CHIP:DMG: { [1728020686.098446][50555:50557] CHIP:DMG: CommandStatusIB = [1728020686.098476][50555:50557] CHIP:DMG: { [1728020686.098502][50555:50557] CHIP:DMG: CommandPathIB = [1728020686.098533][50555:50557] CHIP:DMG: { [1728020686.098563][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020686.098595][50555:50557] CHIP:DMG: ClusterId = 0x3e, [1728020686.098630][50555:50557] CHIP:DMG: CommandId = 0xb, [1728020686.098661][50555:50557] CHIP:DMG: }, [1728020686.098696][50555:50557] CHIP:DMG: [1728020686.098724][50555:50557] CHIP:DMG: StatusIB = [1728020686.098755][50555:50557] CHIP:DMG: { [1728020686.098917][50555:50557] CHIP:DMG: status = 0x00 (SUCCESS), [1728020686.098952][50555:50557] CHIP:DMG: }, [1728020686.098984][50555:50557] CHIP:DMG: [1728020686.099011][50555:50557] CHIP:DMG: }, [1728020686.099042][50555:50557] CHIP:DMG: [1728020686.099067][50555:50557] CHIP:DMG: }, [1728020686.099096][50555:50557] CHIP:DMG: [1728020686.099119][50555:50557] CHIP:DMG: ], [1728020686.099148][50555:50557] CHIP:DMG: [1728020686.099171][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020686.099193][50555:50557] CHIP:DMG: }, [1728020686.099254][50555:50557] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0 [1728020686.099282][50555:50557] CHIP:CTL: Device confirmed that it has received the root certificate [1728020686.099313][50555:50557] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert' [1728020686.099335][50555:50557] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC' [1728020686.099408][50555:50557] CHIP:CTL: Performing next commissioning step 'SendNOC' [1728020686.099493][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020686.099572][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020686.099843][50555:50557] CHIP:EM: <<< [E:24011i S:25080 M:33558548] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020686.100059][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020686.100101][50555:50557] CHIP:CTL: Sent operational certificate to the device [1728020686.100154][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020686.100328][50555:50557] CHIP:EM: <<< [E:24010i S:25080 M:33558549 (Ack:115670347)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.100453][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670347 on exchange 24010i [1728020686.102204][50555:50557] CHIP:EM: >>> [E:24011i S:25080 M:115670348 (Ack:33558548)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.102244][50555:50557] CHIP:EM: Found matching exchange: 24011i, Delegate: 0xffff7c024548 [1728020686.102279][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:33558548 from Retrans Table on exchange 24011i [1728020686.135581][50555:50557] CHIP:EM: >>> [E:24011i S:25080 M:115670349 (Ack:33558548)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020686.135630][50555:50557] CHIP:EM: Found matching exchange: 24011i, Delegate: 0xffff7c024548 [1728020686.135655][50555:50557] CHIP:EM: CHIP MessageCounter:33558548 not in RetransTable on exchange 24011i [1728020686.135692][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020686.135743][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020686.135762][50555:50557] CHIP:DMG: { [1728020686.135780][50555:50557] CHIP:DMG: suppressResponse = false, [1728020686.135797][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020686.135834][50555:50557] CHIP:DMG: [ [1728020686.135857][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020686.135888][50555:50557] CHIP:DMG: { [1728020686.135924][50555:50557] CHIP:DMG: CommandDataIB = [1728020686.135962][50555:50557] CHIP:DMG: { [1728020686.136000][50555:50557] CHIP:DMG: CommandPathIB = [1728020686.136030][50555:50557] CHIP:DMG: { [1728020686.136068][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020686.136099][50555:50557] CHIP:DMG: ClusterId = 0x3e, [1728020686.136139][50555:50557] CHIP:DMG: CommandId = 0x8, [1728020686.136174][50555:50557] CHIP:DMG: }, [1728020686.136212][50555:50557] CHIP:DMG: [1728020686.136249][50555:50557] CHIP:DMG: CommandFields = [1728020686.136279][50555:50557] CHIP:DMG: { [1728020686.136320][50555:50557] CHIP:DMG: 0x0 = 0, [1728020686.136357][50555:50557] CHIP:DMG: 0x1 = 1, [1728020686.136386][50555:50557] CHIP:DMG: }, [1728020686.136412][50555:50557] CHIP:DMG: }, [1728020686.136447][50555:50557] CHIP:DMG: [1728020686.136468][50555:50557] CHIP:DMG: }, [1728020686.136501][50555:50557] CHIP:DMG: [1728020686.136520][50555:50557] CHIP:DMG: ], [1728020686.136552][50555:50557] CHIP:DMG: [1728020686.136572][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020686.136590][50555:50557] CHIP:DMG: }, [1728020686.136653][50555:50557] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008 [1728020686.136722][50555:50557] CHIP:CTL: Device returned status 0 on receiving the NOC [1728020686.136753][50555:50557] CHIP:CTL: Operational credentials provisioned on device 0xffff7c0137b0 [1728020686.136773][50555:50557] CHIP:TOO: Secure Pairing Success [1728020686.136789][50555:50557] CHIP:TOO: CASE establishment successful [1728020686.136814][50555:50557] CHIP:CTL: Successfully finished commissioning step 'SendNOC' [1728020686.136843][50555:50557] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'FindOperational' [1728020686.136876][50555:50557] CHIP:CTL: Performing next commissioning step 'FindOperational' [1728020686.136896][50555:50557] CHIP:IN: Expiring all sessions for node <00000000DEADBEEF, 1>!! [1728020686.136915][50555:50557] CHIP:CSM: FindOrEstablishSession: PeerId = [1:00000000DEADBEEF] [1728020686.136942][50555:50557] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found [1728020686.136971][50555:50557] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: State change 1 --> 2 [1728020686.137005][50555:50557] CHIP:DIS: Resolving 3551521866D894D5:00000000DEADBEEF ... [1728020686.138115][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020686.138412][50555:50557] CHIP:EM: <<< [E:24011i S:25080 M:33558550 (Ack:115670349)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.138566][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:115670349 on exchange 24011i [1728020686.138879][50555:50557] CHIP:DL: Avahi resolve found [1728020686.138954][50555:50557] CHIP:DIS: Node ID resolved for 3551521866D894D5:00000000DEADBEEF [1728020686.138975][50555:50557] CHIP:DIS: Hostname: E45F016941490000 [1728020686.138998][50555:50557] CHIP:DIS: IP Address #1: fe80::588e:4aff:fe48:458 [1728020686.139015][50555:50557] CHIP:DIS: Port: 5565 [1728020686.139045][50555:50557] CHIP:DIS: Mrp Interval idle: 300 ms [1728020686.139070][50555:50557] CHIP:DIS: Mrp Interval active: 2000 ms [1728020686.139091][50555:50557] CHIP:DIS: TCP Supported: 1 [1728020686.139244][50555:50557] CHIP:DIS: UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565: new best score: 7 [1728020686.139269][50555:50557] CHIP:DIS: Checking node lookup status after 2 ms [1728020686.139285][50555:50557] CHIP:DIS: Keeping DNSSD lookup active [1728020686.336670][50555:50557] CHIP:DIS: Checking node lookup status after 200 ms [1728020686.336992][50555:50557] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: Updating device address to UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565 while in state 2 [1728020686.337057][50555:50557] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: State change 2 --> 3 [1728020686.337318][50555:50557] CHIP:IN: SecureSession[0xffff7c03f080]: Allocated Type:2 LSID:25081 [1728020686.337411][50555:50557] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x00000000DEADBEEF [1728020686.339623][50555:50557] CHIP:EM: <<< [E:24012i S:0 M:81919430] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1728020686.339924][50555:50557] CHIP:SC: Sent Sigma1 msg [1728020686.340071][50555:50557] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: State change 3 --> 4 [1728020686.344688][50555:50557] CHIP:EM: >>> [E:24012i S:0 M:181516368 (Ack:81919430)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1728020686.344764][50555:50557] CHIP:EM: Found matching exchange: 24012i, Delegate: 0xffff7c0420c8 [1728020686.344826][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:81919430 from Retrans Table on exchange 24012i [1728020686.344898][50555:50557] CHIP:SC: Received Sigma2 msg [1728020686.344957][50555:50557] CHIP:SC: Peer assigned session session ID 15597 [1728020686.351784][50555:50557] CHIP:SC: Found MRP parameters in the message [1728020686.351876][50555:50557] CHIP:SC: Sending Sigma3 [1728020686.353046][50555:50557] CHIP:EM: <<< [E:24012i S:0 M:81919431 (Ack:181516368)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1728020686.353274][50555:50557] CHIP:SC: Sent Sigma3 msg [1728020686.360696][50555:50557] CHIP:EM: >>> [E:24012i S:0 M:181516369 (Ack:81919431)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) [1728020686.360745][50555:50557] CHIP:EM: Found matching exchange: 24012i, Delegate: 0xffff7c0420c8 [1728020686.360786][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:81919431 from Retrans Table on exchange 24012i [1728020686.360844][50555:50557] CHIP:SC: Success status report received. Session was established [1728020686.365340][50555:50557] CHIP:SC: SecureSession[0xffff7c03f080, LSID:25081]: State change 'kEstablishing' --> 'kActive' [1728020686.365398][50555:50557] CHIP:IN: SecureSession[0xffff7c03f080]: Activated - Type:2 LSID:25081 [1728020686.365422][50555:50557] CHIP:IN: New secure session activated for device <00000000DEADBEEF, 1>, LSID:25081 PSID:15597! [1728020686.365453][50555:50557] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: State change 4 --> 5 [1728020686.365535][50555:50557] CHIP:CTL: Successfully finished commissioning step 'FindOperational' [1728020686.365565][50555:50557] CHIP:CTL: Commissioning stage next step: 'FindOperational' -> 'SendComplete' [1728020686.365600][50555:50557] CHIP:CTL: Performing next commissioning step 'SendComplete' [1728020686.365674][50555:50557] CHIP:DMG: ICR moving to [AddingComm] [1728020686.365705][50555:50557] CHIP:DMG: ICR moving to [AddedComma] [1728020686.365936][50555:50557] CHIP:EM: <<< [E:24013i S:25081 M:149449697] (S) Msg TX to 1:00000000DEADBEEF [94D5] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020686.366149][50555:50557] CHIP:DMG: ICR moving to [CommandSen] [1728020686.366299][50555:50557] CHIP:EM: <<< [E:24012i S:0 M:81919432 (Ack:181516369)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.366419][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:181516369 on exchange 24012i [1728020686.384940][50555:50557] CHIP:EM: >>> [E:24013i S:25081 M:212778241 (Ack:149449697)] (S) Msg RX from 1:00000000DEADBEEF [94D5] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020686.384990][50555:50557] CHIP:EM: Found matching exchange: 24013i, Delegate: 0xffff7c00a0f8 [1728020686.385062][50555:50557] CHIP:EM: Rxd Ack; Removing MessageCounter:149449697 from Retrans Table on exchange 24013i [1728020686.385124][50555:50557] CHIP:DMG: ICR moving to [ResponseRe] [1728020686.385188][50555:50557] CHIP:DMG: InvokeResponseMessage = [1728020686.385217][50555:50557] CHIP:DMG: { [1728020686.385245][50555:50557] CHIP:DMG: suppressResponse = false, [1728020686.385287][50555:50557] CHIP:DMG: InvokeResponseIBs = [1728020686.385324][50555:50557] CHIP:DMG: [ [1728020686.385371][50555:50557] CHIP:DMG: InvokeResponseIB = [1728020686.385411][50555:50557] CHIP:DMG: { [1728020686.385445][50555:50557] CHIP:DMG: CommandDataIB = [1728020686.385480][50555:50557] CHIP:DMG: { [1728020686.385525][50555:50557] CHIP:DMG: CommandPathIB = [1728020686.385563][50555:50557] CHIP:DMG: { [1728020686.385613][50555:50557] CHIP:DMG: EndpointId = 0x0, [1728020686.385654][50555:50557] CHIP:DMG: ClusterId = 0x30, [1728020686.385703][50555:50557] CHIP:DMG: CommandId = 0x5, [1728020686.385741][50555:50557] CHIP:DMG: }, [1728020686.385791][50555:50557] CHIP:DMG: [1728020686.385826][50555:50557] CHIP:DMG: CommandFields = [1728020686.385863][50555:50557] CHIP:DMG: { [1728020686.385914][50555:50557] CHIP:DMG: 0x0 = 0, [1728020686.385968][50555:50557] CHIP:DMG: 0x1 = "" (0 chars), [1728020686.386009][50555:50557] CHIP:DMG: }, [1728020686.386043][50555:50557] CHIP:DMG: }, [1728020686.386093][50555:50557] CHIP:DMG: [1728020686.386125][50555:50557] CHIP:DMG: }, [1728020686.386173][50555:50557] CHIP:DMG: [1728020686.386201][50555:50557] CHIP:DMG: ], [1728020686.386250][50555:50557] CHIP:DMG: [1728020686.386280][50555:50557] CHIP:DMG: InteractionModelRevision = 11 [1728020686.386307][50555:50557] CHIP:DMG: }, [1728020686.386394][50555:50557] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005 [1728020686.386454][50555:50557] CHIP:CTL: Received CommissioningComplete response, errorCode=0 [1728020686.386495][50555:50557] CHIP:CTL: Successfully finished commissioning step 'SendComplete' [1728020686.386534][50555:50557] CHIP:CTL: Commissioning stage next step: 'SendComplete' -> 'Cleanup' [1728020686.386579][50555:50557] CHIP:CTL: Performing next commissioning step 'Cleanup' [1728020686.386624][50555:50557] CHIP:IN: SecureSession[0xffff7c00ae70]: MarkForEviction Type:1 LSID:25080 [1728020686.386652][50555:50557] CHIP:SC: SecureSession[0xffff7c00ae70, LSID:25080]: State change 'kActive' --> 'kPendingEviction' [1728020686.386729][50555:50557] CHIP:IN: SecureSession[0xffff7c00ae70]: Released - Type:1 LSID:25080 [1728020686.386771][50555:50557] CHIP:CTL: Successfully finished commissioning step 'Cleanup' [1728020686.386808][50555:50557] CHIP:TOO: Device commissioning completed with success [1728020686.386901][50555:50557] CHIP:DMG: ICR moving to [AwaitingDe] [1728020686.387198][50555:50557] CHIP:EM: <<< [E:24013i S:25081 M:149449698 (Ack:212778241)] (S) Msg TX to 1:00000000DEADBEEF [94D5] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020686.387442][50555:50557] CHIP:EM: Flushed pending ack for MessageCounter:212778241 on exchange 24013i [1728020686.387706][50555:50555] CHIP:CTL: Shutting down the commissioner [1728020686.387815][50555:50555] CHIP:CTL: Shutting down the controller [1728020686.387879][50555:50555] CHIP:IN: Expiring all sessions for fabric 0x1!! [1728020686.387907][50555:50555] CHIP:IN: SecureSession[0xffff7c03f080]: MarkForEviction Type:2 LSID:25081 [1728020686.387935][50555:50555] CHIP:SC: SecureSession[0xffff7c03f080, LSID:25081]: State change 'kActive' --> 'kPendingEviction' [1728020686.387996][50555:50555] CHIP:IN: SecureSession[0xffff7c03f080]: Released - Type:2 LSID:25081 [1728020686.388030][50555:50555] CHIP:FP: Forgetting fabric 0x1 [1728020686.388070][50555:50555] CHIP:TS: Pending Last Known Good Time: 2023-10-03T16:51:18 [1728020686.388265][50555:50555] CHIP:TS: Previous Last Known Good Time: 2023-10-03T16:51:18 [1728020686.388297][50555:50555] CHIP:TS: Reverted Last Known Good Time to previous value [1728020686.388348][50555:50555] CHIP:CTL: Shutting down the commissioner [1728020686.388440][50555:50555] CHIP:CTL: Shutting down the controller [1728020686.388469][50555:50555] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1728020686.388661][50555:50555] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1728020686.388786][50555:50555] CHIP:FP: Shutting down FabricTable [1728020686.388875][50555:50555] CHIP:TS: Pending Last Known Good Time: 2023-10-03T16:51:18 [1728020686.389632][50555:50555] CHIP:TS: Previous Last Known Good Time: 2023-10-03T16:51:18 [1728020686.389680][50555:50555] CHIP:TS: Reverted Last Known Good Time to previous value [1728020686.389978][50555:50555] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-1NN6BM) [1728020686.390722][50555:50555] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1728020686.390798][50555:50555] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1728020686.390829][50555:50555] CHIP:DL: Inet Layer shutdown [1728020686.390853][50555:50555] CHIP:DL: BLE shutdown [1728020686.390879][50555:50555] CHIP:DL: System Layer shutdown ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ./chip-tool accesscontrol write acl '[{"fabricIndex": 1, "privilege": 5, "authMode": 2, "subjects": [112233], "targets": null}, {"fabricIndex": 1, "privilege": 3, "authMode": 2, "subjects": null, "targets": null}]' 0xDEADBEEF 0 [1728020691.636314][50558:50558] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1728020691.637238][50558:50558] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1728020691.637276][50558:50558] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1728020691.642620][50558:50558] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1728020691.642880][50558:50558] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1728020691.643029][50558:50558] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1728020691.643332][50558:50558] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-nzbgRt) [1728020691.643976][50558:50558] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1728020691.644040][50558:50558] CHIP:DL: NVS set: chip-counters/reboot-count = 4 (0x4) [1728020691.645125][50558:50558] CHIP:DL: Got Ethernet interface: eth0 [1728020691.645702][50558:50558] CHIP:DL: Found the primary Ethernet interface:eth0 [1728020691.646295][50558:50558] CHIP:DL: Got WiFi interface: wlan0 [1728020691.646361][50558:50558] CHIP:DL: Failed to reset WiFi statistic counts [1728020691.646411][50558:50558] CHIP:IN: UDP::Init bind&listen port=0 [1728020691.646512][50558:50558] CHIP:IN: UDP::Init bound to port=46015 [1728020691.646532][50558:50558] CHIP:IN: BLEBase::Init - setting/overriding transport [1728020691.646549][50558:50558] CHIP:IN: TransportMgr initialized [1728020691.646579][50558:50558] CHIP:FP: Initializing FabricTable from persistent storage [1728020691.646723][50558:50558] CHIP:TS: Last Known Good Time: 2023-10-03T16:51:18 [1728020691.648100][50558:50558] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x3551521866D894D5, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1 [1728020691.650080][50558:50558] CHIP:ZCL: Using ZAP configuration... [1728020691.653608][50558:50558] CHIP:DL: Avahi client registered [1728020691.653732][50558:50558] CHIP:CTL: System State Initialized... [1728020691.653871][50558:50558] CHIP:CTL: Setting attestation nonce to random value [1728020691.653906][50558:50558] CHIP:CTL: Setting CSR nonce to random value [1728020691.653959][50558:50558] CHIP:IN: UDP::Init bind&listen port=5550 [1728020691.654079][50558:50558] CHIP:IN: UDP::Init bound to port=5550 [1728020691.654099][50558:50558] CHIP:IN: TransportMgr initialized [1728020691.654366][50558:50560] CHIP:DL: CHIP task running [1728020691.654538][50558:50560] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1728020691.654808][50558:50560] CHIP:CTL: Setting attestation nonce to random value [1728020691.654964][50558:50560] CHIP:CTL: Setting CSR nonce to random value [1728020691.655763][50558:50560] CHIP:CTL: Generating NOC [1728020691.656575][50558:50560] CHIP:FP: Validating NOC chain [1728020691.658111][50558:50560] CHIP:FP: NOC chain validation successful [1728020691.658245][50558:50560] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669 [1728020691.658270][50558:50560] CHIP:TS: Last Known Good Time: 2023-10-03T16:51:18 [1728020691.658288][50558:50560] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1728020691.658305][50558:50560] CHIP:TS: Retaining current Last Known Good Time [1728020691.663751][50558:50560] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1728020691.666147][50558:50560] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-03T16:51:18 [1728020691.668606][50558:50560] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 3551521866D894D5) [1728020691.668654][50558:50560] CHIP:IN: UDP::Init bind&listen port=5550 [1728020691.668770][50558:50560] CHIP:IN: UDP::Init bound to port=5550 [1728020691.668793][50558:50560] CHIP:IN: TransportMgr initialized [1728020691.688080][50558:50560] CHIP:TOO: Sending command to node 0xdeadbeef [1728020691.688537][50558:50560] CHIP:CSM: FindOrEstablishSession: PeerId = [1:00000000DEADBEEF] [1728020691.688568][50558:50560] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found [1728020691.688603][50558:50560] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: State change 1 --> 2 [1728020691.688636][50558:50560] CHIP:DIS: Resolving 3551521866D894D5:00000000DEADBEEF ... [1728020691.690583][50558:50560] CHIP:DL: Avahi resolve found [1728020691.690658][50558:50560] CHIP:DIS: Node ID resolved for 3551521866D894D5:00000000DEADBEEF [1728020691.690680][50558:50560] CHIP:DIS: Hostname: E45F016941490000 [1728020691.690705][50558:50560] CHIP:DIS: IP Address #1: fe80::588e:4aff:fe48:458 [1728020691.690726][50558:50560] CHIP:DIS: Port: 5565 [1728020691.690745][50558:50560] CHIP:DIS: Mrp Interval idle: 300 ms [1728020691.690765][50558:50560] CHIP:DIS: Mrp Interval active: 2000 ms [1728020691.690784][50558:50560] CHIP:DIS: TCP Supported: 1 [1728020691.690910][50558:50560] CHIP:DIS: UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565: new best score: 7 [1728020691.690933][50558:50560] CHIP:DIS: Checking node lookup status after 2 ms [1728020691.690952][50558:50560] CHIP:DIS: Keeping DNSSD lookup active [1728020691.889325][50558:50560] CHIP:DIS: Checking node lookup status after 200 ms [1728020691.889634][50558:50560] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: Updating device address to UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565 while in state 2 [1728020691.889697][50558:50560] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: State change 2 --> 3 [1728020691.889999][50558:50560] CHIP:IN: SecureSession[0xffff8800ae70]: Allocated Type:2 LSID:43090 [1728020691.890094][50558:50560] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x00000000DEADBEEF [1728020691.892258][50558:50560] CHIP:EM: <<< [E:28521i S:0 M:225477708] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1728020691.892685][50558:50560] CHIP:SC: Sent Sigma1 msg [1728020691.892764][50558:50560] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: State change 3 --> 4 [1728020691.900475][50558:50560] CHIP:EM: >>> [E:28521i S:0 M:181516370 (Ack:225477708)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1728020691.900567][50558:50560] CHIP:EM: Found matching exchange: 28521i, Delegate: 0xffff8800df78 [1728020691.900732][50558:50560] CHIP:EM: Rxd Ack; Removing MessageCounter:225477708 from Retrans Table on exchange 28521i [1728020691.900838][50558:50560] CHIP:SC: Received Sigma2 msg [1728020691.900922][50558:50560] CHIP:SC: Peer assigned session session ID 15598 [1728020691.905736][50558:50560] CHIP:SC: Found MRP parameters in the message [1728020691.905817][50558:50560] CHIP:SC: Sending Sigma3 [1728020691.906663][50558:50560] CHIP:EM: <<< [E:28521i S:0 M:225477709 (Ack:181516370)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1728020691.906916][50558:50560] CHIP:SC: Sent Sigma3 msg [1728020691.914112][50558:50560] CHIP:EM: >>> [E:28521i S:0 M:181516371 (Ack:225477709)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) [1728020691.914150][50558:50560] CHIP:EM: Found matching exchange: 28521i, Delegate: 0xffff8800df78 [1728020691.914185][50558:50560] CHIP:EM: Rxd Ack; Removing MessageCounter:225477709 from Retrans Table on exchange 28521i [1728020691.914229][50558:50560] CHIP:SC: Success status report received. Session was established [1728020691.917178][50558:50560] CHIP:SC: SecureSession[0xffff8800ae70, LSID:43090]: State change 'kEstablishing' --> 'kActive' [1728020691.917226][50558:50560] CHIP:IN: SecureSession[0xffff8800ae70]: Activated - Type:2 LSID:43090 [1728020691.917243][50558:50560] CHIP:IN: New secure session activated for device <00000000DEADBEEF, 1>, LSID:43090 PSID:15598! [1728020691.917269][50558:50560] CHIP:DIS: OperationalSessionSetup[1:00000000DEADBEEF]: State change 4 --> 5 [1728020691.917392][50558:50560] CHIP:TOO: cluster 0x0000_001F, attribute: 0x0000_0000, endpoint 0 [1728020691.917456][50558:50560] CHIP:DMG: WriteClient moving to [AddAttribu] [1728020691.917521][50558:50560] CHIP:DMG: WriteClient moving to [AddAttribu] [1728020691.917545][50558:50560] CHIP:DMG: WriteClient moving to [AddAttribu] [1728020691.917852][50558:50560] CHIP:EM: <<< [E:28522i S:43090 M:162488803] (S) Msg TX to 1:00000000DEADBEEF [94D5] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0001:06 (IM:WriteRequest) [1728020691.918045][50558:50560] CHIP:DMG: WriteClient moving to [AwaitingRe] [1728020691.918173][50558:50560] CHIP:EM: <<< [E:28521i S:0 M:225477710 (Ack:181516371)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020691.918273][50558:50560] CHIP:EM: Flushed pending ack for MessageCounter:181516371 on exchange 28521i [1728020691.924177][50558:50560] CHIP:EM: >>> [E:28522i S:43090 M:158923138 (Ack:162488803)] (S) Msg RX from 1:00000000DEADBEEF [94D5] --- Type 0001:07 (IM:WriteResponse) [1728020691.924219][50558:50560] CHIP:EM: Found matching exchange: 28522i, Delegate: 0xffff8800a100 [1728020691.924262][50558:50560] CHIP:EM: Rxd Ack; Removing MessageCounter:162488803 from Retrans Table on exchange 28522i [1728020691.924301][50558:50560] CHIP:DMG: WriteClient moving to [ResponseRe] [1728020691.924478][50558:50560] CHIP:DMG: WriteResponseMessage = [1728020691.924512][50558:50560] CHIP:DMG: { [1728020691.924534][50558:50560] CHIP:DMG: AttributeStatusIBs = [1728020691.924567][50558:50560] CHIP:DMG: [ [1728020691.924592][50558:50560] CHIP:DMG: AttributeStatusIB = [1728020691.924621][50558:50560] CHIP:DMG: { [1728020691.924647][50558:50560] CHIP:DMG: AttributePathIB = [1728020691.924678][50558:50560] CHIP:DMG: { [1728020691.924710][50558:50560] CHIP:DMG: Endpoint = 0x0, [1728020691.924742][50558:50560] CHIP:DMG: Cluster = 0x1f, [1728020691.924775][50558:50560] CHIP:DMG: Attribute = 0x0000_0000, [1728020691.924804][50558:50560] CHIP:DMG: } [1728020691.924835][50558:50560] CHIP:DMG: [1728020691.924861][50558:50560] CHIP:DMG: StatusIB = [1728020691.924889][50558:50560] CHIP:DMG: { [1728020691.924916][50558:50560] CHIP:DMG: status = 0x00 (SUCCESS), [1728020691.924942][50558:50560] CHIP:DMG: }, [1728020691.924969][50558:50560] CHIP:DMG: [1728020691.924992][50558:50560] CHIP:DMG: }, [1728020691.925026][50558:50560] CHIP:DMG: [1728020691.925048][50558:50560] CHIP:DMG: AttributeStatusIB = [1728020691.925072][50558:50560] CHIP:DMG: { [1728020691.925096][50558:50560] CHIP:DMG: AttributePathIB = [1728020691.925121][50558:50560] CHIP:DMG: { [1728020691.925149][50558:50560] CHIP:DMG: Endpoint = 0x0, [1728020691.925177][50558:50560] CHIP:DMG: Cluster = 0x1f, [1728020691.925207][50558:50560] CHIP:DMG: Attribute = 0x0000_0000, [1728020691.925234][50558:50560] CHIP:DMG: ListIndex = Null, [1728020691.925260][50558:50560] CHIP:DMG: } [1728020691.925290][50558:50560] CHIP:DMG: [1728020691.925316][50558:50560] CHIP:DMG: StatusIB = [1728020691.925341][50558:50560] CHIP:DMG: { [1728020691.925368][50558:50560] CHIP:DMG: status = 0x00 (SUCCESS), [1728020691.925394][50558:50560] CHIP:DMG: }, [1728020691.925431][50558:50560] CHIP:DMG: [1728020691.925457][50558:50560] CHIP:DMG: }, [1728020691.925494][50558:50560] CHIP:DMG: [1728020691.925519][50558:50560] CHIP:DMG: AttributeStatusIB = [1728020691.925545][50558:50560] CHIP:DMG: { [1728020691.925571][50558:50560] CHIP:DMG: AttributePathIB = [1728020691.925600][50558:50560] CHIP:DMG: { [1728020691.925631][50558:50560] CHIP:DMG: Endpoint = 0x0, [1728020691.925663][50558:50560] CHIP:DMG: Cluster = 0x1f, [1728020691.925695][50558:50560] CHIP:DMG: Attribute = 0x0000_0000, [1728020691.925727][50558:50560] CHIP:DMG: ListIndex = Null, [1728020691.925757][50558:50560] CHIP:DMG: } [1728020691.925791][50558:50560] CHIP:DMG: [1728020691.925820][50558:50560] CHIP:DMG: StatusIB = [1728020691.925850][50558:50560] CHIP:DMG: { [1728020691.925880][50558:50560] CHIP:DMG: status = 0x00 (SUCCESS), [1728020691.925910][50558:50560] CHIP:DMG: }, [1728020691.925940][50558:50560] CHIP:DMG: [1728020691.925966][50558:50560] CHIP:DMG: }, [1728020691.925995][50558:50560] CHIP:DMG: [1728020691.926019][50558:50560] CHIP:DMG: ], [1728020691.926058][50558:50560] CHIP:DMG: [1728020691.926082][50558:50560] CHIP:DMG: InteractionModelRevision = 11 [1728020691.926105][50558:50560] CHIP:DMG: } [1728020691.926253][50558:50560] CHIP:DMG: WriteClient moving to [AwaitingDe] [1728020691.926534][50558:50560] CHIP:EM: <<< [E:28522i S:43090 M:162488804 (Ack:158923138)] (S) Msg TX to 1:00000000DEADBEEF [94D5] [UDP:[fe80::588e:4aff:fe48:458%veth9916b76]:5565] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020691.926709][50558:50560] CHIP:EM: Flushed pending ack for MessageCounter:158923138 on exchange 28522i [1728020691.926909][50558:50558] CHIP:CTL: Shutting down the commissioner [1728020691.927015][50558:50558] CHIP:CTL: Shutting down the controller [1728020691.927045][50558:50558] CHIP:IN: Expiring all sessions for fabric 0x1!! [1728020691.927068][50558:50558] CHIP:IN: SecureSession[0xffff8800ae70]: MarkForEviction Type:2 LSID:43090 [1728020691.927093][50558:50558] CHIP:SC: SecureSession[0xffff8800ae70, LSID:43090]: State change 'kActive' --> 'kPendingEviction' [1728020691.927116][50558:50558] CHIP:IN: SecureSession[0xffff8800ae70]: Released - Type:2 LSID:43090 [1728020691.927142][50558:50558] CHIP:FP: Forgetting fabric 0x1 [1728020691.927174][50558:50558] CHIP:TS: Pending Last Known Good Time: 2023-10-03T16:51:18 [1728020691.927345][50558:50558] CHIP:TS: Previous Last Known Good Time: 2023-10-03T16:51:18 [1728020691.927405][50558:50558] CHIP:TS: Reverted Last Known Good Time to previous value [1728020691.927450][50558:50558] CHIP:CTL: Shutting down the commissioner [1728020691.927529][50558:50558] CHIP:CTL: Shutting down the controller [1728020691.927553][50558:50558] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1728020691.927719][50558:50558] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1728020691.927825][50558:50558] CHIP:FP: Shutting down FabricTable [1728020691.927856][50558:50558] CHIP:TS: Pending Last Known Good Time: 2023-10-03T16:51:18 [1728020691.927983][50558:50558] CHIP:TS: Previous Last Known Good Time: 2023-10-03T16:51:18 [1728020691.928010][50558:50558] CHIP:TS: Reverted Last Known Good Time to previous value [1728020691.928269][50558:50558] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Y4eRa9) [1728020691.928970][50558:50558] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1728020691.929041][50558:50558] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1728020691.929068][50558:50558] CHIP:DL: Inet Layer shutdown [1728020691.929089][50558:50558] CHIP:DL: BLE shutdown [1728020691.929112][50558:50558] CHIP:DL: System Layer shutdown ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ./chip-tool otasoftwareupdaterequestor announce-otaprovider 0xDEADBEEF 0 0 0 1 0 [1728020699.355354][50561:50561] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1728020699.356308][50561:50561] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1728020699.356355][50561:50561] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1728020699.361589][50561:50561] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1728020699.361884][50561:50561] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1728020699.362009][50561:50561] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1728020699.362376][50561:50561] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-BINdZH) [1728020699.362978][50561:50561] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1728020699.363034][50561:50561] CHIP:DL: NVS set: chip-counters/reboot-count = 5 (0x5) [1728020699.363996][50561:50561] CHIP:DL: Got Ethernet interface: eth0 [1728020699.364683][50561:50561] CHIP:DL: Found the primary Ethernet interface:eth0 [1728020699.365299][50561:50561] CHIP:DL: Got WiFi interface: wlan0 [1728020699.365364][50561:50561] CHIP:DL: Failed to reset WiFi statistic counts [1728020699.365414][50561:50561] CHIP:IN: UDP::Init bind&listen port=0 [1728020699.365517][50561:50561] CHIP:IN: UDP::Init bound to port=50951 [1728020699.365538][50561:50561] CHIP:IN: BLEBase::Init - setting/overriding transport [1728020699.365554][50561:50561] CHIP:IN: TransportMgr initialized [1728020699.365584][50561:50561] CHIP:FP: Initializing FabricTable from persistent storage [1728020699.365730][50561:50561] CHIP:TS: Last Known Good Time: 2023-10-03T16:51:18 [1728020699.367063][50561:50561] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x3551521866D894D5, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1 [1728020699.369049][50561:50561] CHIP:ZCL: Using ZAP configuration... [1728020699.372737][50561:50561] CHIP:DL: Avahi client registered [1728020699.372867][50561:50561] CHIP:CTL: System State Initialized... [1728020699.373004][50561:50561] CHIP:CTL: Setting attestation nonce to random value [1728020699.373038][50561:50561] CHIP:CTL: Setting CSR nonce to random value [1728020699.373095][50561:50561] CHIP:IN: UDP::Init bind&listen port=5550 [1728020699.373217][50561:50561] CHIP:IN: UDP::Init bound to port=5550 [1728020699.373238][50561:50561] CHIP:IN: TransportMgr initialized [1728020699.373493][50561:50563] CHIP:DL: CHIP task running [1728020699.373671][50561:50563] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1728020699.373945][50561:50563] CHIP:CTL: Setting attestation nonce to random value [1728020699.374102][50561:50563] CHIP:CTL: Setting CSR nonce to random value [1728020699.374873][50561:50563] CHIP:CTL: Generating NOC [1728020699.375721][50561:50563] CHIP:FP: Validating NOC chain [1728020699.377270][50561:50563] CHIP:FP: NOC chain validation successful [1728020699.377404][50561:50563] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669 [1728020699.377431][50561:50563] CHIP:TS: Last Known Good Time: 2023-10-03T16:51:18 [1728020699.377449][50561:50563] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1728020699.377466][50561:50563] CHIP:TS: Retaining current Last Known Good Time [1728020699.381724][50561:50563] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1728020699.383801][50561:50563] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-03T16:51:18 [1728020699.386166][50561:50563] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 3551521866D894D5) [1728020699.386215][50561:50563] CHIP:IN: UDP::Init bind&listen port=5550 [1728020699.386337][50561:50563] CHIP:IN: UDP::Init bound to port=5550 [1728020699.386361][50561:50563] CHIP:IN: TransportMgr initialized [1728020699.402252][50561:50563] CHIP:TOO: Sending command to node 0x1 [1728020699.402691][50561:50563] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001] [1728020699.402720][50561:50563] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found [1728020699.402755][50561:50563] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2 [1728020699.402788][50561:50563] CHIP:DIS: Resolving 3551521866D894D5:0000000000000001 ... [1728020699.404564][50561:50563] CHIP:DL: Avahi resolve found [1728020699.404639][50561:50563] CHIP:DIS: Node ID resolved for 3551521866D894D5:0000000000000001 [1728020699.404662][50561:50563] CHIP:DIS: Hostname: AA11F07C547A81EF [1728020699.404687][50561:50563] CHIP:DIS: IP Address #1: fd11:35::2f6c:24fc:c612:64b4 [1728020699.404709][50561:50563] CHIP:DIS: Port: 5540 [1728020699.404728][50561:50563] CHIP:DIS: Mrp Interval idle: 3000 ms [1728020699.404748][50561:50563] CHIP:DIS: Mrp Interval active: 2200 ms [1728020699.404768][50561:50563] CHIP:DIS: TCP Supported: 0 [1728020699.405541][50561:50563] CHIP:DIS: Lookup clearing interface for non LL address [1728020699.405630][50561:50563] CHIP:DIS: UDP:[fd11:35::2f6c:24fc:c612:64b4%veth9916b76]:5540: new best score: 5 [1728020699.405654][50561:50563] CHIP:DIS: Checking node lookup status after 3 ms [1728020699.405672][50561:50563] CHIP:DIS: Keeping DNSSD lookup active [1728020699.603055][50561:50563] CHIP:DIS: Checking node lookup status after 200 ms [1728020699.603190][50561:50563] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd11:35::2f6c:24fc:c612:64b4]:5540 while in state 2 [1728020699.603250][50561:50563] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3 [1728020699.603617][50561:50563] CHIP:IN: SecureSession[0xffff9000ae70]: Allocated Type:2 LSID:46017 [1728020699.603714][50561:50563] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1728020699.605643][50561:50563] CHIP:EM: <<< [E:13812i S:0 M:153862014] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:35::2f6c:24fc:c612:64b4]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1728020699.606056][50561:50563] CHIP:SC: Sent Sigma1 msg [1728020699.606135][50561:50563] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4 [1728020700.312075][50561:50563] CHIP:EM: >>> [E:13812i S:0 M:234218665 (Ack:153862014)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020700.312165][50561:50563] CHIP:EM: Found matching exchange: 13812i, Delegate: 0xffff9000dee8 [1728020700.312236][50561:50563] CHIP:EM: Rxd Ack; Removing MessageCounter:153862014 from Retrans Table on exchange 13812i [1728020700.496217][50561:50563] CHIP:EM: >>> [E:13812i S:0 M:234218666 (Ack:153862014)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1728020700.496323][50561:50563] CHIP:EM: Found matching exchange: 13812i, Delegate: 0xffff9000dee8 [1728020700.496386][50561:50563] CHIP:EM: CHIP MessageCounter:153862014 not in RetransTable on exchange 13812i [1728020700.496492][50561:50563] CHIP:SC: Received Sigma2 msg [1728020700.496579][50561:50563] CHIP:SC: Peer assigned session session ID 12797 [1728020700.503741][50561:50563] CHIP:SC: Found MRP parameters in the message [1728020700.503819][50561:50563] CHIP:SC: Sending Sigma3 [1728020700.504629][50561:50563] CHIP:EM: <<< [E:13812i S:0 M:153862015 (Ack:234218666)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:35::2f6c:24fc:c612:64b4%wpan0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1728020700.504872][50561:50563] CHIP:SC: Sent Sigma3 msg [1728020700.797083][50561:50563] CHIP:EM: >>> [E:13812i S:0 M:234218667 (Ack:153862015)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020700.797141][50561:50563] CHIP:EM: Found matching exchange: 13812i, Delegate: 0xffff9000dee8 [1728020700.797186][50561:50563] CHIP:EM: Rxd Ack; Removing MessageCounter:153862015 from Retrans Table on exchange 13812i [1728020700.992914][50561:50563] CHIP:EM: >>> [E:13812i S:0 M:234218668 (Ack:153862015)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) [1728020700.993011][50561:50563] CHIP:EM: Found matching exchange: 13812i, Delegate: 0xffff9000dee8 [1728020700.993074][50561:50563] CHIP:EM: CHIP MessageCounter:153862015 not in RetransTable on exchange 13812i [1728020700.993177][50561:50563] CHIP:SC: Success status report received. Session was established [1728020701.001794][50561:50563] CHIP:SC: SecureSession[0xffff9000ae70, LSID:46017]: State change 'kEstablishing' --> 'kActive' [1728020701.001900][50561:50563] CHIP:IN: SecureSession[0xffff9000ae70]: Activated - Type:2 LSID:46017 [1728020701.001955][50561:50563] CHIP:IN: New secure session activated for device <0000000000000001, 1>, LSID:46017 PSID:12797! [1728020701.002018][50561:50563] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5 [1728020701.002141][50561:50563] CHIP:TOO: Sending cluster (0x0000002A) command (0x00000000) on endpoint 0 [1728020701.002255][50561:50563] CHIP:DMG: ICR moving to [AddingComm] [1728020701.002442][50561:50563] CHIP:DMG: ICR moving to [AddedComma] [1728020701.002923][50561:50563] CHIP:EM: <<< [E:13813i S:46017 M:202807302] (S) Msg TX to 1:0000000000000001 [94D5] [UDP:[fd11:35::2f6c:24fc:c612:64b4%wpan0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) [1728020701.003280][50561:50563] CHIP:DMG: ICR moving to [CommandSen] [1728020701.003641][50561:50563] CHIP:EM: <<< [E:13812i S:0 M:153862016 (Ack:234218668)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:35::2f6c:24fc:c612:64b4%wpan0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020701.003772][50561:50563] CHIP:EM: Flushed pending ack for MessageCounter:234218668 on exchange 13812i [1728020701.228548][50561:50563] CHIP:EM: >>> [E:13813i S:46017 M:106988300 (Ack:202807302)] (S) Msg RX from 1:0000000000000001 [94D5] --- Type 0001:09 (IM:InvokeCommandResponse) [1728020701.228654][50561:50563] CHIP:EM: Found matching exchange: 13813i, Delegate: 0xffff9000a0f8 [1728020701.228739][50561:50563] CHIP:EM: Rxd Ack; Removing MessageCounter:202807302 from Retrans Table on exchange 13813i [1728020701.228820][50561:50563] CHIP:DMG: ICR moving to [ResponseRe] [1728020701.228926][50561:50563] CHIP:DMG: InvokeResponseMessage = [1728020701.228983][50561:50563] CHIP:DMG: { [1728020701.229037][50561:50563] CHIP:DMG: suppressResponse = false, [1728020701.229094][50561:50563] CHIP:DMG: InvokeResponseIBs = [1728020701.229204][50561:50563] CHIP:DMG: [ [1728020701.229263][50561:50563] CHIP:DMG: InvokeResponseIB = [1728020701.229361][50561:50563] CHIP:DMG: { [1728020701.229424][50561:50563] CHIP:DMG: CommandStatusIB = [1728020701.229496][50561:50563] CHIP:DMG: { [1728020701.229589][50561:50563] CHIP:DMG: CommandPathIB = [1728020701.229676][50561:50563] CHIP:DMG: { [1728020701.229779][50561:50563] CHIP:DMG: EndpointId = 0x0, [1728020701.229860][50561:50563] CHIP:DMG: ClusterId = 0x2a, [1728020701.229963][50561:50563] CHIP:DMG: CommandId = 0x0, [1728020701.230038][50561:50563] CHIP:DMG: }, [1728020701.230143][50561:50563] CHIP:DMG: [1728020701.230212][50561:50563] CHIP:DMG: StatusIB = [1728020701.230317][50561:50563] CHIP:DMG: { [1728020701.230395][50561:50563] CHIP:DMG: status = 0x00 (SUCCESS), [1728020701.230508][50561:50563] CHIP:DMG: }, [1728020701.230586][50561:50563] CHIP:DMG: [1728020701.230680][50561:50563] CHIP:DMG: }, [1728020701.230758][50561:50563] CHIP:DMG: [1728020701.230839][50561:50563] CHIP:DMG: }, [1728020701.230912][50561:50563] CHIP:DMG: [1728020701.230968][50561:50563] CHIP:DMG: ], [1728020701.231039][50561:50563] CHIP:DMG: [1728020701.231096][50561:50563] CHIP:DMG: InteractionModelRevision = 11 [1728020701.231150][50561:50563] CHIP:DMG: }, [1728020701.231276][50561:50563] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_002A Command=0x0000_0000 Status=0x0 [1728020701.231347][50561:50563] CHIP:DMG: ICR moving to [AwaitingDe] [1728020701.231728][50561:50563] CHIP:EM: <<< [E:13813i S:46017 M:202807303 (Ack:106988300)] (S) Msg TX to 1:0000000000000001 [94D5] [UDP:[fd11:35::2f6c:24fc:c612:64b4%wpan0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728020701.231948][50561:50563] CHIP:EM: Flushed pending ack for MessageCounter:106988300 on exchange 13813i [1728020701.232254][50561:50561] CHIP:CTL: Shutting down the commissioner [1728020701.232417][50561:50561] CHIP:CTL: Shutting down the controller [1728020701.232508][50561:50561] CHIP:IN: Expiring all sessions for fabric 0x1!! [1728020701.232550][50561:50561] CHIP:IN: SecureSession[0xffff9000ae70]: MarkForEviction Type:2 LSID:46017 [1728020701.232591][50561:50561] CHIP:SC: SecureSession[0xffff9000ae70, LSID:46017]: State change 'kActive' --> 'kPendingEviction' [1728020701.232631][50561:50561] CHIP:IN: SecureSession[0xffff9000ae70]: Released - Type:2 LSID:46017 [1728020701.232674][50561:50561] CHIP:FP: Forgetting fabric 0x1 [1728020701.232727][50561:50561] CHIP:TS: Pending Last Known Good Time: 2023-10-03T16:51:18 [1728020701.232985][50561:50561] CHIP:TS: Previous Last Known Good Time: 2023-10-03T16:51:18 [1728020701.233030][50561:50561] CHIP:TS: Reverted Last Known Good Time to previous value [1728020701.233118][50561:50561] CHIP:CTL: Shutting down the commissioner [1728020701.233251][50561:50561] CHIP:CTL: Shutting down the controller [1728020701.233293][50561:50561] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1728020701.233543][50561:50561] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1728020701.233727][50561:50561] CHIP:FP: Shutting down FabricTable [1728020701.233786][50561:50561] CHIP:TS: Pending Last Known Good Time: 2023-10-03T16:51:18 [1728020701.233989][50561:50561] CHIP:TS: Previous Last Known Good Time: 2023-10-03T16:51:18 [1728020701.234036][50561:50561] CHIP:TS: Reverted Last Known Good Time to previous value [1728020701.234395][50561:50561] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ETeav4) [1728020701.235495][50561:50561] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1728020701.235607][50561:50561] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1728020701.235653][50561:50561] CHIP:DL: Inet Layer shutdown [1728020701.235689][50561:50561] CHIP:DL: BLE shutdown [1728020701.235725][50561:50561] CHIP:DL: System Layer shutdown ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ./chip-tool otasoftwareupdaterequestor read-event version-applied 1 0 [1728021143.394023][50586:50586] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1728021143.394930][50586:50586] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1728021143.394961][50586:50586] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1728021143.400260][50586:50586] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1728021143.400520][50586:50586] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1728021143.400629][50586:50586] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1728021143.400961][50586:50586] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-XruSha) [1728021143.401533][50586:50586] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1728021143.401582][50586:50586] CHIP:DL: NVS set: chip-counters/reboot-count = 6 (0x6) [1728021143.402499][50586:50586] CHIP:DL: Got Ethernet interface: eth0 [1728021143.403093][50586:50586] CHIP:DL: Found the primary Ethernet interface:eth0 [1728021143.403741][50586:50586] CHIP:DL: Got WiFi interface: wlan0 [1728021143.403806][50586:50586] CHIP:DL: Failed to reset WiFi statistic counts [1728021143.403857][50586:50586] CHIP:IN: UDP::Init bind&listen port=0 [1728021143.403957][50586:50586] CHIP:IN: UDP::Init bound to port=36636 [1728021143.403977][50586:50586] CHIP:IN: BLEBase::Init - setting/overriding transport [1728021143.403994][50586:50586] CHIP:IN: TransportMgr initialized [1728021143.404024][50586:50586] CHIP:FP: Initializing FabricTable from persistent storage [1728021143.404171][50586:50586] CHIP:TS: Last Known Good Time: 2023-10-03T16:51:18 [1728021143.405504][50586:50586] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x3551521866D894D5, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1 [1728021143.407909][50586:50586] CHIP:ZCL: Using ZAP configuration... [1728021143.411438][50586:50586] CHIP:DL: Avahi client registered [1728021143.411561][50586:50586] CHIP:CTL: System State Initialized... [1728021143.411767][50586:50586] CHIP:CTL: Setting attestation nonce to random value [1728021143.411806][50586:50586] CHIP:CTL: Setting CSR nonce to random value [1728021143.411864][50586:50586] CHIP:IN: UDP::Init bind&listen port=5550 [1728021143.411985][50586:50586] CHIP:IN: UDP::Init bound to port=5550 [1728021143.412006][50586:50586] CHIP:IN: TransportMgr initialized [1728021143.412284][50586:50588] CHIP:DL: CHIP task running [1728021143.412464][50586:50588] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1728021143.412750][50586:50588] CHIP:CTL: Setting attestation nonce to random value [1728021143.412914][50586:50588] CHIP:CTL: Setting CSR nonce to random value [1728021143.413721][50586:50588] CHIP:CTL: Generating NOC [1728021143.414568][50586:50588] CHIP:FP: Validating NOC chain [1728021143.416323][50586:50588] CHIP:FP: NOC chain validation successful [1728021143.416474][50586:50588] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669 [1728021143.416503][50586:50588] CHIP:TS: Last Known Good Time: 2023-10-03T16:51:18 [1728021143.416522][50586:50588] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1728021143.416540][50586:50588] CHIP:TS: Retaining current Last Known Good Time [1728021143.423988][50586:50588] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1728021143.427179][50586:50588] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-03T16:51:18 [1728021143.432015][50586:50588] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 3551521866D894D5) [1728021143.432067][50586:50588] CHIP:IN: UDP::Init bind&listen port=5550 [1728021143.432188][50586:50588] CHIP:IN: UDP::Init bound to port=5550 [1728021143.432211][50586:50588] CHIP:IN: TransportMgr initialized [1728021143.449355][50586:50588] CHIP:TOO: Sending command to node 0x1 [1728021143.449758][50586:50588] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001] [1728021143.449785][50586:50588] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found [1728021143.449817][50586:50588] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2 [1728021143.449847][50586:50588] CHIP:DIS: Resolving 3551521866D894D5:0000000000000001 ... [1728021143.451579][50586:50588] CHIP:DL: Avahi resolve found [1728021143.451650][50586:50588] CHIP:DIS: Node ID resolved for 3551521866D894D5:0000000000000001 [1728021143.451670][50586:50588] CHIP:DIS: Hostname: AA11F07C547A81EF [1728021143.451693][50586:50588] CHIP:DIS: IP Address #1: fd11:35::2f6c:24fc:c612:64b4 [1728021143.451712][50586:50588] CHIP:DIS: Port: 5540 [1728021143.451730][50586:50588] CHIP:DIS: Mrp Interval idle: 3000 ms [1728021143.451747][50586:50588] CHIP:DIS: Mrp Interval active: 2200 ms [1728021143.451764][50586:50588] CHIP:DIS: TCP Supported: 0 [1728021143.452467][50586:50588] CHIP:DIS: Lookup clearing interface for non LL address [1728021143.452549][50586:50588] CHIP:DIS: UDP:[fd11:35::2f6c:24fc:c612:64b4%veth9916b76]:5540: new best score: 5 [1728021143.452570][50586:50588] CHIP:DIS: Checking node lookup status after 3 ms [1728021143.452586][50586:50588] CHIP:DIS: Keeping DNSSD lookup active [1728021143.649850][50586:50588] CHIP:DIS: Checking node lookup status after 200 ms [1728021143.649933][50586:50588] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd11:35::2f6c:24fc:c612:64b4]:5540 while in state 2 [1728021143.649955][50586:50588] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3 [1728021143.650122][50586:50588] CHIP:IN: SecureSession[0xffff8c00ae70]: Allocated Type:2 LSID:14254 [1728021143.650167][50586:50588] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1728021143.651069][50586:50588] CHIP:EM: <<< [E:56364i S:0 M:120293731] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:35::2f6c:24fc:c612:64b4]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1728021143.651319][50586:50588] CHIP:SC: Sent Sigma1 msg [1728021143.651351][50586:50588] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4 [1728021144.186273][50586:50588] CHIP:EM: >>> [E:56364i S:0 M:15515240 (Ack:120293731)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728021144.186326][50586:50588] CHIP:EM: Found matching exchange: 56364i, Delegate: 0xffff8c00dd18 [1728021144.186369][50586:50588] CHIP:EM: Rxd Ack; Removing MessageCounter:120293731 from Retrans Table on exchange 56364i [1728021144.369165][50586:50588] CHIP:EM: >>> [E:56364i S:0 M:15515241 (Ack:120293731)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1728021144.369256][50586:50588] CHIP:EM: Found matching exchange: 56364i, Delegate: 0xffff8c00dd18 [1728021144.369310][50586:50588] CHIP:EM: CHIP MessageCounter:120293731 not in RetransTable on exchange 56364i [1728021144.369402][50586:50588] CHIP:SC: Received Sigma2 msg [1728021144.369477][50586:50588] CHIP:SC: Peer assigned session session ID 39399 [1728021144.378160][50586:50588] CHIP:SC: Found MRP parameters in the message [1728021144.378271][50586:50588] CHIP:SC: Sending Sigma3 [1728021144.379583][50586:50588] CHIP:EM: <<< [E:56364i S:0 M:120293732 (Ack:15515241)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:35::2f6c:24fc:c612:64b4%wpan0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1728021144.379931][50586:50588] CHIP:SC: Sent Sigma3 msg [1728021144.663775][50586:50588] CHIP:EM: >>> [E:56364i S:0 M:15515242 (Ack:120293732)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728021144.663876][50586:50588] CHIP:EM: Found matching exchange: 56364i, Delegate: 0xffff8c00dd18 [1728021144.663962][50586:50588] CHIP:EM: Rxd Ack; Removing MessageCounter:120293732 from Retrans Table on exchange 56364i [1728021144.857776][50586:50588] CHIP:EM: >>> [E:56364i S:0 M:15515243 (Ack:120293732)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) [1728021144.857867][50586:50588] CHIP:EM: Found matching exchange: 56364i, Delegate: 0xffff8c00dd18 [1728021144.857922][50586:50588] CHIP:EM: CHIP MessageCounter:120293732 not in RetransTable on exchange 56364i [1728021144.858011][50586:50588] CHIP:SC: Success status report received. Session was established [1728021144.863536][50586:50588] CHIP:SC: SecureSession[0xffff8c00ae70, LSID:14254]: State change 'kEstablishing' --> 'kActive' [1728021144.863624][50586:50588] CHIP:IN: SecureSession[0xffff8c00ae70]: Activated - Type:2 LSID:14254 [1728021144.863670][50586:50588] CHIP:IN: New secure session activated for device <0000000000000001, 1>, LSID:14254 PSID:39399! [1728021144.863726][50586:50588] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5 [1728021144.863849][50586:50588] CHIP:TOO: Sending ReadEvent to: [1728021144.863971][50586:50588] CHIP:TOO: cluster 0x0000_002A, event: 0x0000_0001, endpoint 0 [1728021144.864044][50586:50588] CHIP:DMG: SendReadRequest ReadClient[0xffff8c00a0f0]: Sending Read Request [1728021144.864481][50586:50588] CHIP:EM: <<< [E:56365i S:14254 M:91812900] (S) Msg TX to 1:0000000000000001 [94D5] [UDP:[fd11:35::2f6c:24fc:c612:64b4%wpan0]:5540] --- Type 0001:02 (IM:ReadRequest) [1728021144.864806][50586:50588] CHIP:DMG: MoveToState ReadClient[0xffff8c00a0f0]: Moving to [AwaitingIn] [1728021144.865013][50586:50588] CHIP:EM: <<< [E:56364i S:0 M:120293733 (Ack:15515243)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:35::2f6c:24fc:c612:64b4%wpan0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728021144.865143][50586:50588] CHIP:EM: Flushed pending ack for MessageCounter:15515243 on exchange 56364i [1728021145.072145][50586:50588] CHIP:EM: >>> [E:56365i S:14254 M:46305316 (Ack:91812900)] (S) Msg RX from 1:0000000000000001 [94D5] --- Type 0001:05 (IM:ReportData) [1728021145.072238][50586:50588] CHIP:EM: Found matching exchange: 56365i, Delegate: 0xffff8c00a100 [1728021145.072312][50586:50588] CHIP:EM: Rxd Ack; Removing MessageCounter:91812900 from Retrans Table on exchange 56365i [1728021145.072415][50586:50588] CHIP:DMG: ReportDataMessage = [1728021145.072469][50586:50588] CHIP:DMG: { [1728021145.072518][50586:50588] CHIP:DMG: SuppressResponse = true, [1728021145.072570][50586:50588] CHIP:DMG: InteractionModelRevision = 11 [1728021145.072618][50586:50588] CHIP:DMG: } [1728021145.073036][50586:50588] CHIP:EM: <<< [E:56365i S:14254 M:91812901 (Ack:46305316)] (S) Msg TX to 1:0000000000000001 [94D5] [UDP:[fd11:35::2f6c:24fc:c612:64b4%wpan0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) [1728021145.073275][50586:50588] CHIP:EM: Flushed pending ack for MessageCounter:46305316 on exchange 56365i [1728021145.073609][50586:50586] CHIP:CTL: Shutting down the commissioner [1728021145.073787][50586:50586] CHIP:CTL: Shutting down the controller [1728021145.073888][50586:50586] CHIP:IN: Expiring all sessions for fabric 0x1!! [1728021145.073935][50586:50586] CHIP:IN: SecureSession[0xffff8c00ae70]: MarkForEviction Type:2 LSID:14254 [1728021145.073981][50586:50586] CHIP:SC: SecureSession[0xffff8c00ae70, LSID:14254]: State change 'kActive' --> 'kPendingEviction' [1728021145.074027][50586:50586] CHIP:IN: SecureSession[0xffff8c00ae70]: Released - Type:2 LSID:14254 [1728021145.074077][50586:50586] CHIP:FP: Forgetting fabric 0x1 [1728021145.074135][50586:50586] CHIP:TS: Pending Last Known Good Time: 2023-10-03T16:51:18 [1728021145.074416][50586:50586] CHIP:TS: Previous Last Known Good Time: 2023-10-03T16:51:18 [1728021145.074469][50586:50586] CHIP:TS: Reverted Last Known Good Time to previous value [1728021145.074548][50586:50586] CHIP:CTL: Shutting down the commissioner [1728021145.074705][50586:50586] CHIP:CTL: Shutting down the controller [1728021145.074762][50586:50586] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1728021145.075071][50586:50586] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1728021145.075269][50586:50586] CHIP:FP: Shutting down FabricTable [1728021145.075332][50586:50586] CHIP:TS: Pending Last Known Good Time: 2023-10-03T16:51:18 [1728021145.075636][50586:50586] CHIP:TS: Previous Last Known Good Time: 2023-10-03T16:51:18 [1728021145.075692][50586:50586] CHIP:TS: Reverted Last Known Good Time to previous value [1728021145.076102][50586:50586] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-JSHJEc) [1728021145.077257][50586:50586] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1728021145.077381][50586:50586] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1728021145.077432][50586:50586] CHIP:DL: Inet Layer shutdown [1728021145.077474][50586:50586] CHIP:DL: BLE shutdown [1728021145.077517][50586:50586] CHIP:DL: System Layer shutdown ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$ ubuntu@ubuntu:~/apps$