SiliconLabs / arduino

Arduino Core for Silicon Labs devices
89 stars 16 forks source link

[bug] Direct Device Connection #103

Open leonardpitzu opened 1 day ago

leonardpitzu commented 1 day ago

Hardware

SparkFun Thing Plus Matter - MGM240P

Core version

2.2.0

Arduino IDE version

2.3.3

Operating system

macOS 15.1

Radio stack variant

Matter

OpenThread Border Router device (if using Matter)

Apple iPhone 15 PRO

Issue description

According to https://appleinsider.com/articles/24/09/18/apple-enables-direct-thread-control-for-smart-home-devices-with-ios-18 iOS 18 supports direct Thread connection. Currently this does not work - the thread device is detected by the phone and pairing is initiated. The process hangs at the "adding devices" step and times out eventually with iOS presenting and error "Unable to Add Accessory".

Serial output

12:45:42.403 -> Matter temperature sensor 12:45:42.799 -> Matter device is not commissioned 12:45:42.799 -> Commission it to your Matter hub with the manual pairing code or QR code 12:45:42.833 -> Manual pairing code: 34970112332 12:45:42.833 -> QR code URL: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A6FCJ142C00KA0648G00 12:46:04.228 -> Waiting for Thread network... 12:46:38.355 -> Connected to Thread network 12:46:38.355 -> Waiting for Matter device discovery...

RTT output (if using Matter)

No response

Minimal reproducer code

#include <Matter.h>
#include <MatterTemperature.h>

MatterTemperature matter_temp_sensor;

void setup()
{
  Serial.begin(115200);
  Matter.begin();
  matter_temp_sensor.begin();

  Serial.println("Matter temperature sensor");

  if (!Matter.isDeviceCommissioned()) {
    Serial.println("Matter device is not commissioned");
    Serial.println("Commission it to your Matter hub with the manual pairing code or QR code");
    Serial.printf("Manual pairing code: %s\n", Matter.getManualPairingCode().c_str());
    Serial.printf("QR code URL: %s\n", Matter.getOnboardingQRCodeUrl().c_str());
  }
  while (!Matter.isDeviceCommissioned()) {
    delay(200);
  }

  Serial.println("Waiting for Thread network...");
  while (!Matter.isDeviceThreadConnected()) {
    delay(200);
  }
  Serial.println("Connected to Thread network");

  Serial.println("Waiting for Matter device discovery...");
  while (!matter_temp_sensor.is_online()) {
    delay(200);
  }
  Serial.println("Matter device is now online");
}

void loop()
{
  float current_cpu_temp = getCPUTemp();
  matter_temp_sensor.set_measured_value_celsius(current_cpu_temp);
  Serial.printf("Current CPU temperature: %.02f C\n", current_cpu_temp);
  delay(2000);
}
silabs-bozont commented 1 day ago

Hello @leonardpitzu, According to Apple pairing with your iPhone should also work: https://support.apple.com/en-il/102078 From the Serial logs it looks like the pairing finishes - but the device doesn't get discovered. Can you get me an RTT output from your device during pairing? Which version of iOS are you running on your iPhone?

silabs-bozont commented 1 day ago

I've tried it with my iPhone 16 (iOS 18.1.1) while unplugging all my other Thread border routers. Looks like for me it doesn't even start pairing with just the phone present.

leonardpitzu commented 1 day ago

You need at least an iPhone 15 Pro as the other, older iPhones, are missing the hardware for this to work. I have an iPhone 15 Pro running 18.1.1 (latest official iOS release). I will try to get the logs as soon as I get back home.

leonardpitzu commented 1 day ago

RTT log

00> [00:00:00.000][silabs ]================================================== 00> [00:00:00.000][silabs ]Arduino Matter device starting 00> [00:00:00.000][silabs ]================================================== 00> [00:00:00.000][silabs ]Init CHIP Stack 00> [00:00:00.000][info ][DL] Setting device name to : "Arduino Matter device" 00> [00:00:00.000][silabs ]Initializing OpenThread stack 00> [00:00:00.000][info ][DL] OpenThread started: OK 00> [00:00:00.000][info ][DL] Setting OpenThread device type to ROUTER 00> [00:00:00.000][silabs ]Starting OpenThread task 00> [00:00:00.000][info ][SVR] Subscription persistence not supported 00> [00:00:00.000][info ][SVR] Server initializing... 00> [00:00:00.000][detail][FP] Initializing FabricTable from persistent storage 00> [00:00:00.000][info ][TS] Last Known Good Time: 2023-10-10T16:28:52 00> [00:00:00.000][info ][DMG] AccessControl: initializing 00> [00:00:00.000][info ][DMG] Examples::AccessControlDelegate::Init 00> [00:00:00.000][info ][DMG] AccessControl: setting 00> [00:00:00.000][info ][DMG] Default[00:07:08.826][info ][DL] Connect Event for handle : 2 00> [00:07:08.976][info ][DL] evt_UNKNOWN id = 090600a0 00> [00:07:09.605][info ][DL] Char Write Req, char : 23 00> [00:07:09.605][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 9) 00> [00:07:09.606][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:09.606][info ][BLE] local and remote recv window sizes = 5 00> [00:07:09.606][info ][BLE] selected BTP version 4 00> [00:07:09.606][info ][BLE] using BTP fragment sizes rx 244 / tx 244. 00> [00:07:09.725][info ][DL] HandleTXcharCCCDWrite - Config Flags value : 2 00> [00:07:09.725][info ][DL] CHIPoBLE subscribe received 00> [00:07:09.725][info ][DL] _OnPlatformEvent kCHIPoBLESubscribe 00> [00:07:09.726][detail][IN] BLE EndPoint 0x2000c980 Connection Complete 00> [00:07:09.726][info ][DL] _OnPlatformEvent default: event->Type = 32775 00> [00:07:09.785][info ][DL] Tx Confirmation received 00> [00:07:09.785][info ][DL] stop soft timer 00> [00:07:09.786][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:09.787][info ][DL] Char Write Req, char : 23 00> [00:07:09.787][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 103) 00> [00:07:09.787][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:09.787][info ][EM] >>> [E:31778r S:0 M:126040044] (U) Msg RX from 0:7D93283821199A73 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) 00> [00:07:09.787][detail][EM] Handling via exchange: 31778r, Delegate: 0x2000bfe8 00> [00:07:09.788][detail][SC] Received PBKDF param request 00> [00:07:09.788][detail][SC] Peer assigned session ID 20610 00> [00:07:09.788][detail][SC] Found MRP parameters in the message 00> [00:07:09.789][detail][SC] Including MRP parameters in PBKDF param response 00> [00:07:09.790][info ][EM] <<< [E:31778r S:0 M:222289911] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) 00> [00:07:09.791][detail][SC] Sent PBKDF param response 00> [00:07:09.791][info ][S[00:07:09.845][info ][DL] Tx Confirmation received 00> [00:07:09.845][info ][DL] stop soft timer 00> [00:07:09.845][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:09.846][info ][DL] Char Write Req, char : 23 00> [00:07:09.846][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 97) 00> [00:07:09.846][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:09.847][info ][EM] >>> [E:31778r S:0 M:126040045] (U) Msg RX from 0:7D93283821199A73 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) 00> [00:07:09.847][detail][EM] Found matching exchange: 31778r, Delegate: 0x2000bfe8 00> [00:07:09.847][detail][SC] Received spake2p msg1 00> [00:07:09.927][info ][EM] <<< [E:31778r S:0 M:222289912] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) 00> [00:07:09.928][detail][SC] Sent spake2p msg2 00> [00:07:09.965][info ][DL] Tx Confirmation received 00> [00:07:09.965][info ][DL] stop soft timer 00> [00:07:09.966][info ][DL] Char Write Req, char : 23 00> [00:07:09.966][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 64) 00> [00:07:09.966][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:09.966][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:09.966][info ][EM] >>> [E:31778r S:0 M:126040046] (U) Msg RX from 0:7D93283821199A73 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) 00> [00:07:09.967][detail][EM] Found matching exchange: 31778r, Delegate: 0x2000bfe8 00> [00:07:09.967][detail][SC] Received spake2p msg3 00> [00:07:09.967][detail][SC] Sending status report. Protocol code 0, exchange 31778 00> [00:07:09.968][info ][EM] <<< [E:31778r S:0 M:222289913] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) 00> [00:07:09.971][info ][SC] SecureSession[0x20009950, LSID:9763]: State change 'kEstablishing' --> 'kActive' 00> [00:07:09.972][detail][IN] SecureSession[0x20009950]: Activated - Type:1 LSID:9763 00> [00:07:09.972][detail[00:07:10.025][info ][DL] Tx Confirmation received 00> [00:07:10.025][info ][DL] stop soft timer 00> [00:07:10.026][info ][DL] Char Write Req, char : 23 00> [00:07:10.026][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 56) 00> [00:07:10.026][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.027][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.027][info ][EM] >>> [E:31779r S:9763 M:201214648] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.028][detail][EM] Handling via exchange: 31779r, Delegate: 0x20006d34 00> [00:07:10.028][detail][IM] Received Read request 00> [00:07:10.028][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.029][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.029][detail][DMG] <RE:Run> Cluster 1d, Attribute 3 is dirty 00> [00:07:10.029][detail][DMG] Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0003 (expanded=0) 00> [00:07:10.029][detail][DMG] <RE> Sending report (payload has 40 bytes)... 00> [00:07:10.030][i[00:07:10.085][info ][DL] Tx Confirmation received 00> [00:07:10.085][info ][DL] stop soft timer 00> [00:07:10.085][info ][DL] Char Write Req, char : 23 00> [00:07:10.086][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 56) 00> [00:07:10.086][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.086][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.087][info ][EM] >>> [E:31780r S:9763 M:201214649] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.087][detail][EM] Handling via exchange: 31780r, Delegate: 0x20006d34 00> [00:07:10.087][detail][IM] Received Read request 00> [00:07:10.088][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.088][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.088][detail][DMG] <RE:Run> Cluster 1d, Attribute 1 is dirty 00> [00:07:10.088][detail][DMG] Reading attribute: Cluster=0x0000_001D Endpoint=0 AttributeId=0x0000_0001 (expanded=0) 00> [00:07:10.089][detail][DMG] <RE> Sending report (payload has 70 bytes)... 00> [00:07:10.089][i[00:07:10.145][info ][DL] Tx Confirmation received 00> [00:07:10.145][info ][DL] stop soft timer 00> [00:07:10.146][info ][DL] Char Write Req, char : 23 00> [00:07:10.146][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 57) 00> [00:07:10.146][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.146][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.147][info ][EM] >>> [E:31781r S:9763 M:201214650] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.147][detail][EM] Handling via exchange: 31781r, Delegate: 0x20006d34 00> [00:07:10.148][detail][IM] Received Read request 00> [00:07:10.148][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.148][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.149][detail][DMG] <RE:Run> Cluster 31, Attribute fffc is dirty 00> [00:07:10.149][detail][DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) 00> [00:07:10.149][detail][DMG] <RE> Sending report (payload has 37 bytes)... 00> [00:07:10.150[00:07:10.205][info ][DL] Tx Confirmation received 00> [00:07:10.206][info ][DL] stop soft timer 00> [00:07:10.206][info ][DL] Char Write Req, char : 23 00> [00:07:10.207][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 56) 00> [00:07:10.207][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.207][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.208][info ][EM] >>> [E:31782r S:9763 M:201214651] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.208][detail][EM] Handling via exchange: 31782r, Delegate: 0x20006d34 00> [00:07:10.208][detail][IM] Received Read request 00> [00:07:10.208][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.208][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.208][detail][DMG] <RE:Run> Cluster 31, Attribute 1 is dirty 00> [00:07:10.208][detail][DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) 00> [00:07:10.208][detail][DMG] <RE> Sending report (payload has 36 bytes)... 00> [00:07:10.209][i[00:07:10.265][info ][DL] Tx Confirmation received 00> [00:07:10.265][info ][DL] stop soft timer 00> [00:07:10.266][info ][DL] Char Write Req, char : 23 00> [00:07:10.266][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 57) 00> [00:07:10.266][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.266][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.267][info ][EM] >>> [E:31783r S:9763 M:201214652] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.267][detail][EM] Handling via exchange: 31783r, Delegate: 0x20006d34 00> [00:07:10.268][detail][IM] Received Read request 00> [00:07:10.268][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.268][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.268][detail][DMG] <RE:Run> Cluster 31, Attribute fffc is dirty 00> [00:07:10.269][detail][DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) 00> [00:07:10.269][detail][DMG] <RE> Sending report (payload has 37 bytes)... 00> [00:07:10.270[00:07:10.325][info ][DL] Tx Confirmation received 00> [00:07:10.325][info ][DL] stop soft timer 00> [00:07:10.326][info ][DL] Char Write Req, char : 23 00> [00:07:10.326][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 59) 00> [00:07:10.327][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.327][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.328][info ][EM] >>> [E:31784r S:9763 M:201214653] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.328][detail][EM] Handling via exchange: 31784r, Delegate: 0x20006d34 00> [00:07:10.328][detail][IM] Received Read request 00> [00:07:10.329][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.329][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.329][detail][DMG] <RE:Run> Cluster 1349fc00, Attribute 1 is dirty 00> [00:07:10.329][detail][DMG] Reading attribute: Cluster=0x1349_FC00 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) 00> [00:07:10.329][detail][DMG] <RE> Sending report (payload has 36 bytes)... 00> [00:07:10.[00:07:10.385][info ][DL] Tx Confirmation received 00> [00:07:10.385][info ][DL] stop soft timer 00> [00:07:10.386][info ][DL] Char Write Req, char : 23 00> [00:07:10.386][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 55) 00> [00:07:10.386][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.386][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.387][info ][EM] >>> [E:31785r S:9763 M:201214654] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.387][detail][EM] Handling via exchange: 31785r, Delegate: 0x20006d34 00> [00:07:10.387][detail][IM] Received Read request 00> [00:07:10.388][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.388][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.388][detail][DMG] <RE:Run> Cluster 33, Attribute 0 is dirty 00> [00:07:10.388][detail][DMG] Reading attribute: Cluster=0x0000_0033 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) 00> [00:07:10.389][detail][DMG] <RE> Sending report (payload has 77 bytes)... 00> [00:07:10.390][i[00:07:10.445][info ][DL] Tx Confirmation received 00> [00:07:10.445][info ][DL] stop soft timer 00> [00:07:10.446][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.446][info ][DL] Char Write Req, char : 23 00> [00:07:10.447][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 136) 00> [00:07:10.447][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.448][info ][EM] >>> [E:31786r S:9763 M:201214655] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.448][detail][EM] Handling via exchange: 31786r, Delegate: 0x20006d34 00> [00:07:10.448][detail][IM] Received Read request 00> [00:07:10.451][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.451][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.451][detail][DMG] <RE:Run> Cluster 31, Attribute 3 is dirty 00> [00:07:10.451][detail][DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) 00> [00:07:10.451][detail][DMG] <RE:Run> Cluster 28, Attribute 4 is dirty 00> [00:07:10.452][detail][DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) 00> [00:07:10.452][detail][DMG] <RE:Run> Cluster 28, Attribute 2 is dirty 00> [00:07:10.452][detail][DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) 00> [00:07:10.452][[00:07:10.505][info ][DL] Tx Confirmation received 00> [00:07:10.505][info ][DL] stop soft timer 00> [00:07:10.505][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.565][info ][DL] Tx Confirmation received 00> [00:07:10.565][info ][DL] stop soft timer 00> [00:07:10.565][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.566][info ][DL] Char Write Req, char : 23 00> [00:07:10.566][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 111) 00> [00:07:10.567][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.567][info ][EM] >>> [E:31787r S:9763 M:201214656] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) 00> [00:07:10.568][detail][EM] Handling via exchange: 31787r, Delegate: 0x20006d34 00> [00:07:10.568][detail][IM] Received Read request 00> [00:07:10.570][detail][DMG] IM RH moving to [CanStartReporting] 00> [00:07:10.570][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu 00> [00:07:10.570][detail][DMG] <RE:Run> Cluster 46, Attribute 2 is dirty 00> [00:07:10.570][detail][DMG] Reading attribute: Cluster=0x0000_0046 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) 00> [00:07:10.570][detail][DMG] <RE:Run> Cluster 46, Attribute 1 is dirty 00> [00:07:10.571][deta[00:07:10.571][detail][DMG] <RE:Run> Cluster 46, Attribute 7 is dirty 00> [00:07:10.571][detail][DMG] Reading attribute: Cluster=0x0000_0046 Endpoint=0 AttributeId=0x0000_0007 (expanded=0) 00> [00:07:10.572][detail][DMG] <RE:Run> Cluster 46, Attribute 6 is dirty 00> [00:07:10.572][detail][DMG] Reading attri[00:07:10.625][info ][DL] Tx Confirmation received 00> [00:07:10.625][info ][DL] stop soft timer 00> [00:07:10.625][info ][DL] Char Write Req, char : 23 00> [00:07:10.626][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 70) 00> [00:07:10.626][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.626][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.627][info ][EM] >>> [E:31788r S:9763 M:201214657] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:10.627][detail][EM] Handling via exchange: 31788r, Delegate: 0x20006d34 00> [00:07:10.628][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 00> [00:07:10.628][info ][FS] GeneralCommissioning: Received ArmFailSafe (60s) 00> [00:07:10.628][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to e1685073 00> [00:07:10.628][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:10.628][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:10.628][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:10.629][detail][DMG] [00:07:10.685][info ][DL] Tx Confirmation received 00> [00:07:10.685][info ][DL] stop soft timer 00> [00:07:10.685][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.686][info ][DL] Char Write Req, char : 23 00> [00:07:10.686][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 75) 00> [00:07:10.686][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.687][info ][EM] >>> [E:31789r S:9763 M:201214658] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:10.688][detail][EM] Handling via exchange: 31789r, Delegate: 0x20006d34 00> [00:07:10.688][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 00> [00:07:10.688][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to e1685074 00> [00:07:10.689][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:10.689][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:10.689][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:10.689][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:10.690][in[00:07:10.745][info ][DL] Tx Confirmation received 00> [00:07:10.746][info ][DL] stop soft timer 00> [00:07:10.746][info ][DL] Char Write Req, char : 23 00> [00:07:10.746][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 67) 00> [00:07:10.747][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.747][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.748][info ][EM] >>> [E:31790r S:9763 M:201214659] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:10.748][detail][EM] Handling via exchange: 31790r, Delegate: 0x20006d34 00> [00:07:10.748][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 00> [00:07:10.749][info ][ZCL] OpCreds: Certificate Chain request received for PAI 00> [00:07:10.749][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:10.749][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:10.749][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:10.749][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:10.750][info ][E[00:07:10.805][info ][DL] Tx Confirmation received 00> [00:07:10.805][info ][DL] stop soft timer 00> [00:07:10.805][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.865][info ][DL] Tx Confirmation received 00> [00:07:10.866][info ][DL] stop soft timer 00> [00:07:10.866][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.925][info ][DL] Tx Confirmation received 00> [00:07:10.925][info ][DL] stop soft timer 00> [00:07:10.926][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:10.926][info ][DL] Char Write Req, char : 23 00> [00:07:10.926][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 67) 00> [00:07:10.926][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:10.927][info ][EM] >>> [E:31791r S:9763 M:201214660] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:10.927][detail][EM] Handling via exchange: 31791r, Delegate: 0x20006d34 00> [00:07:10.928][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 00> [00:07:10.928][info ][ZCL] OpCreds: Certificate Chain request received for DAC 00> [00:07:10.928][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:10.928][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:10.928][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:10.929][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:10.930][info ][E[00:07:10.985][info ][DL] Tx Confirmation received 00> [00:07:10.985][info ][DL] stop soft timer 00> [00:07:10.986][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:11.045][info ][DL] Tx Confirmation received 00> [00:07:11.045][info ][DL] stop soft timer 00> [00:07:11.045][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:11.105][info ][DL] Tx Confirmation received 00> [00:07:11.105][info ][DL] stop soft timer 00> [00:07:11.105][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:11.106][info ][DL] Char Write Req, char : 23 00> [00:07:11.106][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 99) 00> [00:07:11.107][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:11.107][info ][EM] >>> [E:31792r S:9763 M:201214661] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:11.108][detail][EM] Handling via exchange: 31792r, Delegate: 0x20006d34 00> [00:07:11.108][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 00> [00:07:11.108][info ][ZCL] OpCreds: Received an AttestationRequest command 00> [00:07:11.115][info ][ZCL] OpCreds: AttestationRequest successful. 00> [00:07:11.115][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:11.115][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:11.115][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:11.115][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:11.116][info ][EM] <<< [E:31792r S:9763 M:104300653] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) 00> [00:07:11.117][detail][DMG] Command handler moving to [CommandSen] 00> [00:07:11.117][detail][DMG] Command handler moving to [AwaitingDe] 00> [00:07:11.166][info ][DL] Tx Confirmation received 00> [00:07:11.166][info ][DL] stop soft timer 00> [00:07:11.166][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:11.225][info ][DL] Tx Confirmation received 00> [00:07:11.225][info ][DL] stop soft timer 00> [00:07:11.225][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:11.285][info ][DL] Tx Confirmation received 00> [00:07:11.285][info ][DL] stop soft timer 00> [00:07:11.286][info ][DL] Char Write Req, char : 23 00> [00:07:11.286][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 70) 00> [00:07:11.287][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:11.287][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:11.288][info ][EM] >>> [E:31793r S:9763 M:201214662] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:11.288][detail][EM] Handling via exchange: 31793r, Delegate: 0x20006d34 00> [00:07:11.288][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 00> [00:07:11.289][info ][FS] GeneralCommissioning: Received ArmFailSafe (60s) 00> [00:07:11.289][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to e1685075 00> [00:07:11.289][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:11.289][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:11.289][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:11.289][detail][DMG] [00:07:11.345][info ][DL] Tx Confirmation received 00> [00:07:11.345][info ][DL] stop soft timer 00> [00:07:11.345][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:12.816][info ][DL] Char Write Req, char : 23 00> [00:07:12.816][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 99) 00> [00:07:12.816][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:12.817][info ][EM] >>> [E:31794r S:9763 M:201214663] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:12.817][detail][EM] Handling via exchange: 31794r, Delegate: 0x20006d34 00> [00:07:12.818][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 00> [00:07:12.818][info ][ZCL] OpCreds: Received a CSRRequest command 00> [00:07:12.818][detail][ZCL] OpCreds: Finding fabric with fabricIndex 0x0 00> [00:07:12.832][info ][ZCL] OpCreds: AllocatePendingOperationalKey succeeded 00> [00:07:12.837][info ][ZCL] OpCreds: CSRRequest successful. 00> [00:07:12.837][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:12.837][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:12.837][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:12.837][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:12.838][info ][EM] <<< [E:31794r S:9763 M:104300655] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) 00> [00:07:12.839][detail][DMG] Command handler moving to [CommandSen] 00> [00:07:12.839][detail][DMG] Command handler moving to [AwaitingDe] 00> [00:07:12.875][info ][DL] Tx Confirmation received 00> [00:07:12.875][info ][DL] stop soft timer 00> [00:07:12.875][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:12.935][info ][DL] Tx Confirmation received 00> [00:07:12.935][info ][DL] stop soft timer 00> [00:07:12.935][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:12.937][info ][DL] Char Write Req, char : 23 00> [00:07:12.937][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 244) 00> [00:07:12.937][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:12.996][info ][DL] Char Write Req, char : 23 00> [00:07:12.996][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 71) 00> [00:07:12.996][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:12.997][info ][EM] >>> [E:31795r S:9763 M:201214664] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:12.997][detail][EM] Handling via exchange: 31795r, Delegate: 0x20006d34 00> [00:07:12.998][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B 00> [00:07:12.998][info ][ZCL] OpCreds: Received an AddTrustedRootCertificate command 00> [00:07:13.005][info ][ZCL] OpCreds: AddTrustedRootCertificate successful. 00> [00:07:13.005][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:13.005][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:13.005][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:13.005][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:13.006][info ][EM] <<< [E:31795r S:9763 M:104300656] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) 00> [00:07:13.007][detail][DMG] Command handler moving to [CommandSen] 00> [00:07:13.007][detail][DMG] Command handler moving to [AwaitingDe] 00> [00:07:13.055][info ][DL] Tx Confirmation received 00> [00:07:13.055][info ][DL] stop soft timer 00> [00:07:13.055][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:13.057][info ][DL] Char Write Req, char : 23 00> [00:07:13.057][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 244) 00> [00:07:13.057][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:13.116][info ][DL] Char Write Req, char : 23 00> [00:07:13.116][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 110) 00> [00:07:13.116][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:13.117][info ][EM] >>> [E:31796r S:9763 M:201214665] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:13.118][detail][EM] Handling via exchange: 31796r, Delegate: 0x20006d34 00> [00:07:13.118][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 00> [00:07:13.118][info ][ZCL] OpCreds: Received an AddNOC command 00> [00:07:13.120][info ][FP] Validating NOC chain 00> [00:07:13.129][info ][FP] NOC chain validation successful 00> [00:07:13.129][info ][FP] Added new fabric at index: 0x1 00> [00:07:13.129][info ][FP] Assigned compressed fabric ID: 0xF97A37306DB7DE46, node ID: 0x00000000F260AC1B 00> [00:07:13.129][info ][TS] Last Known Good Time: 2023-10-10T16:28:52 00> [00:07:13.130][info ][TS] New proposed Last Known Good Time: 2024-12-02T19:24:41 00> [00:07:13.130][info ][TS] Updating pending Last Known Good Time to 2024-12-02T19:24:41 00> [00:07:13.130][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to efbf3a5 00> [00:07:13.130][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to efbf3a6 00> [00:07:13.141][detail][EVL] LogEvent event number: 0x0000000000060002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Epoch timestamp: 0x000000DC6AD647F5 00> [00:07:13.141][info ][ZCL] OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x00000000196F9AF3 00> [00:07:13.142][detail][DL] Using Thread extended MAC for hostname. 00> [00:07:13.142][info ][DIS] Advertise operational node F97A37306DB7DE46-00000000F260AC1B 00> [00:07:13.142][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to efbf3a7 00> [00:07:13.142][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to efbf3a8 00> [00:07:13.142][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:13.142][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:13.142][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:13.143][info ][ZCL] OpCreds: successfully created fabric index 0x1 via AddNOC 00> [00:07:13.143][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:13.144][info [00:07:13.175][info ][DL] Tx Confirmation received 00> [00:07:13.175][info ][DL] stop soft timer 00> [00:07:13.175][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:13.176][info ][DL] Char Write Req, char : 23 00> [00:07:13.176][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 168) 00> [00:07:13.177][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:13.177][info ][EM] >>> [E:31797r S:9763 M:201214666] (S) Msg RX from 1:FFFFFFFB00000000 [DE46] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:13.178][detail][EM] Handling via exchange: 31797r, Delegate: 0x20006d34 00> [00:07:13.178][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 00> [00:07:13.179][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:13.179][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:13.180][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:13.180][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to e1685076 00> [00:07:13.180][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:13.181][info ][EM] <<< [E:31797r S:9763 M:104300658] (S) Msg TX to 1:FFFFFFFB00000000 [DE46] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) 00> [00:07:13.181][detail][DMG] Command handler moving to [CommandSen] 00> [00:07:13.181][detail][DMG] Command handler moving to [AwaitingDe] 00> [00:07:13.235][info ][DL] Tx Confirmation received 00> [00:07:13.235][info ][DL] stop soft timer 00> [00:07:13.236][info ][DL] Char Write Req, char : 23 00> [00:07:13.236][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 70) 00> [00:07:13.236][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:13.237][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:13.237][info ][EM] >>> [E:31798r S:9763 M:201214667] (S) Msg RX from 1:FFFFFFFB00000000 [DE46] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:13.238][detail][EM] Handling via exchange: 31798r, Delegate: 0x20006d34 00> [00:07:13.238][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 00> [00:07:13.238][info ][FS] GeneralCommissioning: Received ArmFailSafe (121s) 00> [00:07:13.239][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to e1685077 00> [00:07:13.239][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:13.239][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:13.239][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:13.239][detail][DMG][00:07:13.295][info ][DL] Tx Confirmation received 00> [00:07:13.295][info ][DL] stop soft timer 00> [00:07:13.296][info ][DL] Char Write Req, char : 23 00> [00:07:13.296][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 78) 00> [00:07:13.296][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:13.296][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:13.297][info ][EM] >>> [E:31799r S:9763 M:201214668] (S) Msg RX from 1:FFFFFFFB00000000 [DE46] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:13.297][detail][EM] Handling via exchange: 31799r, Delegate: 0x20006d34 00> [00:07:13.298][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 00> [00:07:13.319][detail][DMG] Decreasing reference count for CommandHandler, remaining 1 00> [00:07:13.319][info ][DL] _OnPlatformEvent default: event->Type = 32772 00> [00:07:13.321][info ][DL] _OnPlatformEvent default: event->Type = 32777 00> [00:07:13.321][detail][DL] OpenThread State Changed (Flags: 0x111fd11d) 00> [00:07:13.321][detail][DL] Device Role: DETACHED 00> [00:07:13.321][detail][DL] Network Name: MyHome3 00> [00:07:13.322][detail][DL] PAN Id: 0xE1BC 00> [00:07:13.322][detail][DL] Extended PAN Id: 0x297E7F600F3A46B0 00> [00:07:13.322][detail][DL] Channel: 25 00> [00:07:13.322][detail][DL] Mesh Prefix: fd29:7e7f:600f:0:0:0:0:0/64 00> [00:07:13.322][detail][DL] Thread Unicast Addresses: 00> [00:07:13.322][detail][DL] fd29:7e7f:600f:0:1ad9:4f57:5a49:7e7c/64 valid 00> [00:07:13.323][detail][DL] fe80:0:0:0:f456:b086:e72f:3cd8/64 valid preferred 00> [00:07:14.317][info ][DL] _OnPlatformEvent default: event->Type = 32777 00> [00:07:14.318][detail][DL] OpenThread State Changed (Flags: 0x00000100) 00> [00:07:14.616][info ][DL] SRP Client was started, detected server: fd29:7e7f:600f:0000:0000:00ff:fe00:fc10 00> [00:07:14.616][info ][DL] _OnPlatformEvent default: event->Type = 32777 00> [00:07:14.617][detail][DL] OpenThread State Changed (Flags: 0x200012a4) 00> [00:07:14.617][detail][DL] Device Role: CHILD 00> [00:07:14.617][detail][DL] Partition Id: 0x7CA43661 00> [00:07:14.620][info ][DL] _OnPlatformEvent default: event->Type = 32777 00> [00:07:14.620][detail][DL] Thread Attached updating Multicast address 00> [00:07:14.620][info ][SVR] Joining Multicast groups 00> [00:07:14.620][detail][DL] OpenThread State Changed (Flags: 0x00000001) 00> [00:07:14.621][detail][DL] Thread Unicast Addresses: 00> [00:07:14.621][detail][DL] fdd8:6c5b:730b:0:9d3b:cf18:e424:5558/64 valid preferred 00> [00:07:14.621][detail][DL] fd29:7e7f:600f:0:0:ff:fe00:98a/64 valid rloc 00> [00:07:14.621][detail][DL] fd29:7e7f:600f:0:1ad9:4f57:5a49:7e7c/64 valid 00> [00:07:14.622][detail][DL] fe80:0:0:0:f456:b086:e72f:3cd8/64 valid preferred 00> [00:07:14.624][info ][DL] _OnPlatformEvent default: event->Type = 32769 00> [00:07:14.625][silabs ]Scheduling OTA Requestor initialization 00> [00:07:14.625][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:14.625][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:14.625][detail[00:07:14.626][detail][DMG] Command handler moving to [CommandSen] 00> [00:07:14.626][detail][DMG] Command handler moving to [AwaitingDe] 00> [00:07:14.626][info ][DL] _OnPlatformEvent default: event->Type = 32783 00> [00:07:14.626][detail][DL] Using Thread extended MAC for hostname. 00> [00:07:14.626][info ][DIS] Advertise operational node F97A37306DB7DE46-00000000F260AC1B 00> [00:07:14.626][info ][SVR] Operational advertising enabled 00> [00:07:14.675][info ][DL] Tx Confirmation received 00> [00:07:14.675][info ][DL] stop soft timer 00> [00:07:14.675][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:14.918][detail][DL] SRP update succeeded 00> [00:07:14.918][info ][DL] _OnPlatformEvent default: event->Type = 32784 00> [00:07:14.918][info ][SVR] Server initialization complete 00> [00:07:14.918][info ][DIS] Updating services using commissioning mode 0 00> [00:07:14.918][detail][DL] Using Thread extended MAC for hostname. 00> [00:07:14.919][info ][DIS] Advertise operational node F97A37306DB7DE46-00000000F260AC1B 00> [00:07:14.919][info ][DL] advertising srp service: F97A37306DB7DE46-00000000F260AC1B._matter._tcp 00> [00:07:14.919][info ][DL] _OnPlatformEvent default: event->Type = 32788 00> [00:07:15.279][detail][DL] SRP update succeeded 00> [00:07:17.166][info ][DL] Char Write Req, char : 23 00> [00:07:17.166][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:17.166][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:17.626][info ][SWU] Stopping the watchdog timer 00> [00:07:17.626][info ][SWU] Starting the periodic query timer, timeout: 86400 seconds 00> [00:07:17.626][detail][DMG] Endpoint 0, Cluster 0x0000_002A update version to b56bdf0a 00> [00:07:17.627][detail][DMG] Endpoint 0, Cluster 0x0000_002A update version to b56bdf0b 00> [00:07:19.715][info ][DL] Tx Confirmation received 00> [00:07:19.715][info ][DL] stop soft timer 00> [00:07:19.715][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:22.206][info ][DL] Char Write Req, char : 23 00> [00:07:22.206][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:22.206][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:24.755][info ][DL] Tx Confirmation received 00> [00:07:24.755][info ][DL] stop soft timer 00> [00:07:24.755][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:27.246][info ][DL] Char Write Req, char : 23 00> [00:07:27.246][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:27.246][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:29.574][info ][DL] _OnPlatformEvent default: event->Type = 32777 00> [00:07:29.574][detail][DL] OpenThread State Changed (Flags: 0x00000064) 00> [00:07:29.574][detail][DL] Device Role: ROUTER 00> [00:07:29.795][info ][DL] Tx Confirmation received 00> [00:07:29.795][info ][DL] stop soft timer 00> [00:07:29.795][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:32.286][info ][DL] Char Write Req, char : 23 00> [00:07:32.286][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:32.286][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:34.835][info ][DL] Tx Confirmation received 00> [00:07:34.835][info ][DL] stop soft timer 00> [00:07:34.836][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:37.326][info ][DL] Char Write Req, char : 23 00> [00:07:37.326][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:37.326][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:39.875][info ][DL] Tx Confirmation received 00> [00:07:39.875][info ][DL] stop soft timer 00> [00:07:39.876][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:42.366][info ][DL] Char Write Req, char : 23 00> [00:07:42.366][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:42.366][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:44.916][info ][DL] Tx Confirmation received 00> [00:07:44.916][info ][DL] stop soft timer 00> [00:07:44.916][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:47.406][info ][DL] Char Write Req, char : 23 00> [00:07:47.406][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:47.407][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:49.956][info ][DL] Tx Confirmation received 00> [00:07:49.956][info ][DL] stop soft timer 00> [00:07:49.957][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:52.446][info ][DL] Char Write Req, char : 23 00> [00:07:52.446][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:52.447][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:54.996][info ][DL] Tx Confirmation received 00> [00:07:54.997][info ][DL] stop soft timer 00> [00:07:54.997][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:07:57.486][info ][DL] Char Write Req, char : 23 00> [00:07:57.486][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:07:57.487][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:59.676][info ][DL] Char Write Req, char : 23 00> [00:07:59.676][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 69) 00> [00:07:59.677][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:07:59.677][info ][EM] >>> [E:31800r S:9763 M:201214669] (S) Msg RX from 1:FFFFFFFB00000000 [DE46] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:07:59.678][detail][EM] Handling via exchange: 31800r, Delegate: 0x20006d34 00> [00:07:59.678][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 00> [00:07:59.678][info ][FS] GeneralCommissioning: Received ArmFailSafe (120s) 00> [00:07:59.678][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to e1685079 00> [00:07:59.679][detail][DMG] Command handler moving to [ Preparing] 00> [00:07:59.679][detail][DMG] Command handler moving to [AddingComm] 00> [00:07:59.679][detail][DMG] Command handler moving to [AddedComma] 00> [00:07:59.679][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:07:59[00:07:59.681][detail][DMG] Command handler moving to [CommandSen] 00> [00:07:59.681][detail][DMG] Command handler moving to [AwaitingDe] 00> [00:07:59.736][info ][DL] Tx Confirmation received 00> [00:07:59.736][info ][DL] stop soft timer 00> [00:07:59.737][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:02.226][info ][DL] Char Write Req, char : 23 00> [00:08:02.226][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:02.226][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:04.776][info ][DL] Tx Confirmation received 00> [00:08:04.776][info ][DL] stop soft timer 00> [00:08:04.777][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:07.266][info ][DL] Char Write Req, char : 23 00> [00:08:07.266][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:07.267][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:09.816][info ][DL] Tx Confirmation received 00> [00:08:09.816][info ][DL] stop soft timer 00> [00:08:09.817][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:12.306][info ][DL] Char Write Req, char : 23 00> [00:08:12.306][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:12.307][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:14.856][info ][DL] Tx Confirmation received 00> [00:08:14.857][info ][DL] stop soft timer 00> [00:08:14.857][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:17.346][info ][DL] Char Write Req, char : 23 00> [00:08:17.346][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:17.347][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:19.896][info ][DL] Tx Confirmation received 00> [00:08:19.897][info ][DL] stop soft timer 00> [00:08:19.897][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:22.386][info ][DL] Char Write Req, char : 23 00> [00:08:22.386][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:22.387][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:24.937][info ][DL] Tx Confirmation received 00> [00:08:24.937][info ][DL] stop soft timer 00> [00:08:24.937][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:27.426][info ][DL] Char Write Req, char : 23 00> [00:08:27.427][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:27.427][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:29.977][info ][DL] Tx Confirmation received 00> [00:08:29.977][info ][DL] stop soft timer 00> [00:08:29.977][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:32.466][info ][DL] Char Write Req, char : 23 00> [00:08:32.467][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:32.467][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:35.017][info ][DL] Tx Confirmation received 00> [00:08:35.017][info ][DL] stop soft timer 00> [00:08:35.017][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:37.506][info ][DL] Char Write Req, char : 23 00> [00:08:37.507][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:37.507][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:40.057][info ][DL] Tx Confirmation received 00> [00:08:40.057][info ][DL] stop soft timer 00> [00:08:40.057][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:42.546][info ][DL] Char Write Req, char : 23 00> [00:08:42.546][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:42.547][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:44.677][info ][DL] Char Write Req, char : 23 00> [00:08:44.677][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 69) 00> [00:08:44.677][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:44.678][info ][EM] >>> [E:31801r S:9763 M:201214670] (S) Msg RX from 1:FFFFFFFB00000000 [DE46] --- Type 0001:08 (IM:InvokeCommandRequest) 00> [00:08:44.678][detail][EM] Handling via exchange: 31801r, Delegate: 0x20006d34 00> [00:08:44.679][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 00> [00:08:44.679][info ][FS] GeneralCommissioning: Received ArmFailSafe (120s) 00> [00:08:44.679][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to e168507a 00> [00:08:44.679][detail][DMG] Command handler moving to [ Preparing] 00> [00:08:44.679][detail][DMG] Command handler moving to [AddingComm] 00> [00:08:44.679][detail][DMG] Command handler moving to [AddedComma] 00> [00:08:44.680][detail][DMG] Decreasing reference count for CommandHandler, remaining 0 00> [00:08:44.680][info ][EM] <<< [E:31801r S:9763 M:104300662] (S) Msg TX to 1:FFFFFFFB00000000 [DE46] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) 00> [00:08:44.681][detail][DMG] Command handler moving to [CommandSen] 00> [00:08:44.681][de[00:08:44.737][info ][DL] Tx Confirmation received 00> [00:08:44.737][info ][DL] stop soft timer 00> [00:08:44.737][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:47.227][info ][DL] Char Write Req, char : 23 00> [00:08:47.227][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:47.227][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:49.777][info ][DL] Tx Confirmation received 00> [00:08:49.777][info ][DL] stop soft timer 00> [00:08:49.777][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:52.267][info ][DL] Char Write Req, char : 23 00> [00:08:52.267][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:52.267][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:54.817][info ][DL] Tx Confirmation received 00> [00:08:54.817][info ][DL] stop soft timer 00> [00:08:54.817][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:08:57.307][info ][DL] Char Write Req, char : 23 00> [00:08:57.307][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:08:57.307][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:08:59.857][info ][DL] Tx Confirmation received 00> [00:08:59.857][info ][DL] stop soft timer 00> [00:08:59.857][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:02.346][info ][DL] Char Write Req, char : 23 00> [00:09:02.347][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:02.347][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:04.897][info ][DL] Tx Confirmation received 00> [00:09:04.897][info ][DL] stop soft timer 00> [00:09:04.897][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:07.386][info ][DL] Char Write Req, char : 23 00> [00:09:07.387][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:07.387][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:09.937][info ][DL] Tx Confirmation received 00> [00:09:09.937][info ][DL] stop soft timer 00> [00:09:09.937][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:12.426][info ][DL] Char Write Req, char : 23 00> [00:09:12.427][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:12.427][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:14.977][info ][DL] Tx Confirmation received 00> [00:09:14.977][info ][DL] stop soft timer 00> [00:09:14.977][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:17.466][info ][DL] Char Write Req, char : 23 00> [00:09:17.467][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:17.467][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:20.017][info ][DL] Tx Confirmation received 00> [00:09:20.017][info ][DL] stop soft timer 00> [00:09:20.017][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:22.506][info ][DL] Char Write Req, char : 23 00> [00:09:22.506][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:22.507][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:25.057][info ][DL] Tx Confirmation received 00> [00:09:25.057][info ][DL] stop soft timer 00> [00:09:25.057][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:27.546][info ][DL] Char Write Req, char : 23 00> [00:09:27.546][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:27.547][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:30.096][info ][DL] Tx Confirmation received 00> [00:09:30.097][info ][DL] stop soft timer 00> [00:09:30.097][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:32.586][info ][DL] Char Write Req, char : 23 00> [00:09:32.586][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:32.587][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:35.136][info ][DL] Tx Confirmation received 00> [00:09:35.137][info ][DL] stop soft timer 00> [00:09:35.137][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:37.626][info ][DL] Char Write Req, char : 23 00> [00:09:37.626][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:37.627][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:40.176][info ][DL] Tx Confirmation received 00> [00:09:40.177][info ][DL] stop soft timer 00> [00:09:40.177][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:42.666][info ][DL] Char Write Req, char : 23 00> [00:09:42.666][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:42.667][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived 00> [00:09:45.216][info ][DL] Tx Confirmation received 00> [00:09:45.216][info ][DL] stop soft timer 00> [00:09:45.217][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm 00> [00:09:47.707][info ][DL] Char Write Req, char : 23 00> [00:09:47.707][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 2, len 3) 00> [00:09:47.708][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived