• State Verified Answer
  • Replies 8 replies
  • Subscribers 75 subscribers
  • Views 1824 views
  • Users 0 members are here
Attachments (3) Download All
Nordic Case Info
  • Case ID: 300751
Options

Adding clusters to Matter application read measured value keeps giving 0

kendrik-dev

Hi! I am a junior developer trying Matter out and I was following some documentations to to integrate sensors with the NRF52840 Development Kit to retrieve readings.

So far, I have been able to follow the examples for ADC to integrate an analog sensor (I'm starting with a light-dependent resistor to keep things simple) and have been successful in getting a reading out of it! I have also been able to add Matter clusters, build, flash and send commands to it based on the Template documentation and Adding clusters to Matter application documentation. However, during the integration, I could not help but realize that prior to integrating the sensor (actually, I successfully validated the analog pin's integration by reading its value within the Init function before deciding to take a step back, actually, I believe the use case I would be looking for would be IlluminanceMeasurement instead, but as I am following the documentations, I removed the sensor from the process and am thus using TemperatureMeasurement), the MeasuredValue is 0 as shown in the image below where I am using the Linux CHIP tool even after running the command multiple times:

Attached below is the configuration rendered by the ZAP tool for all my enabled clusters:

I have enabled OnOff attribute and commands for the cluster as shown below.

I have also enabled the MeasuredValue attribute Temperature Measurement as shown below.

I have also followed the other steps in the documentation, and have tried to trace various parts of the code to see that the task used to generate a randomized temperature does not appear to run. I have also managed to validate that the end device (NRF52840 development kit) is receiving commands from the CHIP tool as shown in the attached log file (I used screen to log this data):

Fullscreen screenlog.txt Download 
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: 172595 [EM]>>> [E:25861r M:108046430] (U) Msg RX from 0:AB736A562AA1D241 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 172606 [EM]Handling via exchange: 25861r, Delegate: 0x200042e0
I: 172612 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 172619 [IN]CASE Server disabling CASE session setups
I: 172625 [EM]<<< [E:25861r M:141505733 (Ack:108046430)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 172637 [IN](U) Sending msg 141505733 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:51644'
D: 172648 [EM]Flushed pending ack for MessageCounter:108046430 on exchange 25861r
I: 172655 [SC]Received Sigma1 msg
D: 172658 [SC]Found MRP parameters in the message
D: 172663 [SC]Peer assigned session key ID 35050
I: 172671 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 172891 [SC]Including MRP parameters
I: 172895 [EM]<<< [E:25861r M:141505734 (Ack:108046430)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 172908 [IN](U) Sending msg 141505734 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:51644'
I: 172918 [SC]Sent Sigma2 msg
I: 173203 [EM]>>> [E:25861r M:108046431 (Ack:141505734)] (U) Msg RX from 0:AB736A562AA1D241 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 173215 [EM]Found matching exchange: 25861r, Delegate: 0x200042fc
D: 173222 [EM]Rxd Ack; Removing MessageCounter:141505734 from Retrans Table on exchange 25861r
I: 173230 [EM]<<< [E:25861r M:141505735 (Ack:108046431)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 173243 [IN](U) Sending msg 141505735 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:51644'
D: 173253 [EM]Flushed pending ack for MessageCounter:108046431 on exchange 25861r
I: 173261 [SC]Received Sigma3 msg
E: 173268 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 173551 [SC]Sending status report. Protocol code 0, exchange 25861
I: 173557 [EM]<<< [E:25861r M:141505736 (Ack:108046431)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 173570 [IN](U) Sending msg 141505736 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:51644'
I: 173581 [SC]SecureSession[0x200037e0]: Moving from state 'kEstablishing' --> 'kActive'
D: 173589 [IN]SecureSession[0x200037e0]: Activated - Type:2 LSID:43045
D: 173596 [IN]New secure session activated for device <000000000001B669, 1>, LSID:43045 PSID:35050!
I: 173605 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 173611 [IN]CASE Server enabling CASE session setups
D: 173616 [IN]SecureSession[0x20003670]: Allocated Type:2 LSID:43046
D: 173622 [SC]Allocated SecureSession (0x20003670) - waiting for Sigma1 msg
I: 173644 [EM]>>> [E:25862r M:14925382] (S) Msg RX from 1:000000000001B669 [4F8F] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 173656 [EM]Handling via exchange: 25862r, Delegate: 0x2000d504
D: 173663 [DMG]Received command for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0001
I: 173670 [ZCL]On/Off set value: 1 1
I: 173674 [ZCL]Toggle on/off from 0 to 1
D: 173677 [DMG]Endpoint 1, Cluster 0x0000_0006 update version to 619cbed9
D: 173684 [DMG]Command handler moving to [ Preparing]
D: 173689 [DMG]Command handler moving to [AddingComm]
D: 173694 [DMG]Command handler moving to [AddedComma]
D: 173698 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 173706 [EM]<<< [E:25862r M:196796406 (Ack:14925382)] (S) Msg TX to 1:000000000001B669 [4F8F] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 173718 [IN](S) Sending msg 196796406 on secure session with LSID: 43045
D: 173726 [DMG]Command handler moving to [CommandSen]
D: 173731 [DMG]Command handler moving to [AwaitingDe]
I: 173737 [EM]>>> [E:25861r M:108046432 (Ack:141505736)] (U) Msg RX from 0:AB736A562AA1D241 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 173750 [EM]Found matching exchange: 25861r, Delegate: (nil)
D: 173756 [EM]Rxd Ack; Removing MessageCounter:141505736 from Retrans Table on exchange 25861r
I: 173766 [EM]>>> [E:25862r M:14925383 (Ack:196796406)] (S) Msg RX from 1:000000000001B669 [4F8F] --- Type 0000:10 (SecureChannel:StandaloneAck)
DEM]Rxd Ack; Removing MessageCounter:196796406 from Retrans Table on exchange 25862r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[E:21368r M:109347775] (U) Msg RX fr2DA578A1776 [0000] --- 0:0000000000000000 04205 [IN](U) Sending msg 141505737 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:53730'
D: 204215 [EM]Flushed pending a parameters in the message
D: 204230 [SC]Peer assigned session kI: 204239 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 204460 [SC]Including MRP parameters
I: 204464 [EM]<<< [E:21368r M:141505738 (Ack:109347775)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 204476 [IN](U) Sending msg 141505738 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:53730'
I: 204487 [SC]Sent Sigma2 msg
I: 204726 [EM]>>> [E:21368r M:109347776 (Ack:141505738)] (U) Msg RX from 0:F05752DA578A1776 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 204739 [EM]Found matching exchange: 21368r, Delegate: 0x200042fc
D: 204745 [EM]Rxd Ack; Removing MessageCounter:141505738 from Retrans Table on exchange 21368r
I: 204753 [EM]<<< [E:21368r M:141505739 (Ack:109347776)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 204766 [IN](U) Sending msg 141505739 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:53730'
D: 204777 [EM]Flushed pending ack for MessageCounter:109347776 on exchange 21368r
I: 204784 [SC]Received Sigma3 msg
E: 204791 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 205065 [SC]Sending status report. Protocol code 0, exchange 21368
I: 205072 [EM]<<< [E:21368r M:141505740 (Ack:109347776)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 205084 [IN](U) Sending msg 141505740 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:53730'
I: 205096 [SC]SecureSession[0x20003670]: Moving from state 'kEstablishing' --> 'kActive'
D: 205104 [IN]SecureSession[0x20003670]: Activated - Type:2 LSID:43046
D: 205111 [IN]New secure session activated for device <000000000001B669, 1>, LSID:43046 PSID:54555!
I: 205120 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 205126 [IN]CASE Server enabling CASE session setups
D: 205131 [IN]SecureSession[0x20003898]: Allocated Type:2 LSID:43047
D: 205137 [SC]Allocated SecureSession (0x20003898) - waiting for Sigma1 msg
I: 205170 [EM]>>> [E:21369r M:234000798] (S) Msg RX from 1:000000000001B669 [4F8F] --- Type 0001:02 (IM:ReadRequest)
D: 205182 [EM]Handling via exchange: 21369r, Delegate: 0x2000d504
D: 205188 [IM]Received Read request
D: 205192 [DMG]IM RH moving to [GeneratingReports]
D: 205197 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 205205 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 205210 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 205219 [DMG]<RE> Sending report (payload has 37 bytes)...
I: 205226 [EM]<<< [E:21369r M:205411592 (Ack:234000798)] (S) Msg TX to 1:000000000001B669 [4F8F] --- Type 0001:05 (IM:ReportData)
I: 205237 [IN](S) Sending msg 205411592 on secure session with LSID: 43046
D: 205245 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 205250 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 205258 [DMG]IM RH moving to [AwaitingDestruction]
D: 205262 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 205269 [EM]>>> [E:21368r M:109347777 (Ack:141505740)] (U) Msg RX from 0:F05752DA578A1776 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 205282 [EM]Found matching exchange: 21368r, Delegate: (nil)
D: 205288 [EM]Rxd Ack; Removing MessageCounter:141505740 from Retrans Table on exchange 21368r
I: 205333 [EM]>>> [E:21369r M:234000799 (Ack:205411592)] (S) Msg RX from 1:000000000001B669 [4F8F] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 205346 [EM]Found matching exchange: 21369r, Delegate: (nil)
D: 205352 [EM]Rxd Ack; Removing MessageCounter:205411592 from Retrans Table on exchange 21369r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[51~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[2~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[5~~~~~~~~~~~~~~~~[3~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[9~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[33D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~1A~~~~~~~~~~~~~~~~~~~~~1A~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[2D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~59D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: 603501 [EM]>>> [E:10076r M:93262476] (U) Msg RX from 0:1F70FA085023B9A7 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 603512 [EM]Handling via exchange: 10076r, Delegate: 0x200042e0
I: 603518 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I(Ack:93262476)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 603543 [IN](U) Sending msg 141505741 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7aD: 603569 [SC]Peer assigned session key ID 4762
I: 603577 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 603797 [SC]Including MRP parameters
I: 603801 [EM]<<< [E:10076r M:141505742 (Ack:93262476)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 603813 [IN](U) Sending msg 141505742 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:42847'
I: 603825 [SC]Sent Sigma2 msg
I: 603945 [EM]>>> [E:10076r M:93262477 (Ack:141505742)] (U) Msg RX from 0:1F70FA085023B9A7 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 603958 [EM]Found matching exchange: 10076r, Delegate: 0x200042fc
D: 603964 [EM]Rxd Ack; Removing MessageCounter:141505742 from Retrans Table on exchange 10076r
I: 603972 [EM]<<< [E:10076r M:141505743 (Ack:93262477)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 603985 [IN](U) Sending msg 141505743 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:42847'
D: 603996 [EM]Flushed pending ack for MessageCounter:93262477 on exchange 10076r
I: 604003 [SC]Received Sigma3 msg
E: 604010 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 604286 [SC]Sending status report. Protocol code 0, exchange 10076
I: 604292 [EM]<<< [E:10076r M:141505744 (Ack:93262477)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 604305 [IN](U) Sending msg 141505744 to IP address 'UDP:[fd09:9880:1c2b:fdb3:166e:7a8:70d4:2647]:42847'
I: 604316 [SC]SecureSession[0x20003898]: Moving from state 'kEstablishing' --> 'kActive'
D: 604324 [IN]SecureSession[0x20003898]: Activated - Type:2 LSID:43047
D: 604331 [IN]Ne for device <000000000001B669, 1>, LSID:43047 PSID:4762!
I: 604340 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 604346 [IN]CASE Server enabling CASE session setups
D: 604351 [IN]SecureSession[0x20003950]: Allocated Type:2 LSID:43048
D: 604359 [SC]Allocated SecureSession (0x20003950) - waiting for Sigma1 msg
I: 604368 [EM]>>> [E:10077r M:75967799] (S) Msg RX from 1:000000000001B669 [4F8F] --- Type 0001:02 (IM:ReadRequest)
D: 604378 [EM]Handling via exchange: 10077r, Delegate: 0x2000d504
D: 604384 [IM]Received Read request
D: 604388 [DMG]IM RH moving to [GeneratingReports]
D: 604392 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 604401 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 604406 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 604415 [DMG]<RE> Sending report (payload has 37 bytes)...
I: 604422 [EM]<<< [E:10077r M:37209051 (Ack:75967799)] (S) Msg TX to 1:000000000001B669 [4F8F] --- Type 0001:05 (IM:ReportData)
I: 604433 [IN](S) Sending msg 37209051 on secure session with LSID: 43047
D: 604440 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 604445 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 604453 [DMG]IM RH moving to [AwaitingDestruction]
D: 604458 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 604464 [EM]>>> [E:10076r M:93262478 (Ack:141505744)] (U) Msg RX from 0:1F70FA085023B9A7 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 604478 [EM]Found matching exchange: 10076r, Delegate: (nil)
D: 604484 [EM]Rxd Ack; Removing MessageCounter:141505744 from Retrans Table on exchange 10076r
I: 604493 [EM]>>> [E:10077r M:75967800 (Ack:37209051)] (S) Msg RX from 1:000000000001B669 [4F8F] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 604506 [EM]Found matching exchange: 10077r, Delegate: (nil)
D: 604511 [EM]Rxd Ack; Removing MessageCounter:37209051 from Retrans Table on exchange 10077r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~2A~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~D: 642107 [DL]OpenThread St~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[3~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~7D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~2A~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~A~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~37D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[2~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[3~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~D: 1022753 [DIS]Extended discovery timed out
I: 1022757 [DIS]Updating services using commissioning mode 0
D: 1022763 [DL]Using Thread extended MAC for hostname.
I: 1022768 [DIS]Advertise operational node 447E1E4C787B4F8F-0000000000000001
I: 1022775 [DL]removing srp service: 8B484905D69D1ED0._matterc._udp
D: 1023360 [DL]SRP update succeeded
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: 3391657 [EM]>>> [E:25024r M:82554133] (U) Msg RX from 0:02A569D500F28ECD [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 3391668 [EM]Handling via exchange: 25024r, Delegate: 0x200042e0
I: 3391674 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 3391682 [IN]CASE Server disabling CASE session setups
I: 3391687 [EM]<<< [E:25024r M:141505745 (Ack:82554133)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 3391700 [IN](U) Sending msg 141505745 to IP address 'UDP:[fd09:9880:1c2b:fdb3:782a:fd75:649b:a29e]:43876'
D: 3391710 [EM]Flushed pending ack for MessageCounter:82554133 on exchange 25024r
I: 3391718 [SC]Received Sigma1 msg
D: 3391721 [SC]Found MRP parameters in the message
D: 3391726 [SC]Peer assigned session key ID 35410
I: 3391734 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 3391955 [SC]Including MRP parameters
I: 3391959 [EM]<<< [E:25024r M:141505746 (Ack:82554133)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 3391972 [IN](U) Sending msg 141505746 to IP address 'UDP:[fd09:9880:1c2b:fdb3:782a:fd75:649b:a29e]:43876'
I: 3391983 [SC]Sent Sigma2 msg
I: 3392145 [EM]>>> [E:25024r M:82554134 (Ack:141505746)] (U) Msg RX from 0:02A569D500F28ECD [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 3392157 [EM]Found matching exchange: 25024r, Delegate: 0x200042fc
D: 3392164 [EM]Rxd Ack; Removing MessageCounter:141505746 from Retrans Table on exchange 25024r
I: 3392172 [EM]<<< [E:25024r M:141505747 (Ack:82554134)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 3392185 [IN](U) Sending msg 141505747 to IP address 'UDP:[fd09:9880:1c2b:fdb3:782a:fd75:649b:a29e]:43876'
D: 3392195 [EM]Flushed pending ack for MessageCounter:82554134 on exchange 25024r
I: 3392203 [SC]Received Sigma3 msg
E: 3392210 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 3392487 [SC]Sending status report. Protocol code 0, exchange 25024
I: 3392494 [EM]<<< 4)] (U) Msg:ing msg 141505748 to IcureSession[0x20003950]: --> 'kctivate92 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 3392548 [IN]CASE Server enabling CASE seC]Allocatedg RX from 1:000000000001B669 [4F8F] --- Type 0001:02 (IM:ReadRequest)
Delegate:M]Received Read request
D: 3392591 [DMG]IM RH moving to [GeneratingReports]
D: 3392595 [DMG]Building Reports fon = 0 DirtyGeneration = 0]<RE:RuAttribute 0 is dirtttributeId=0x0000_0000 (expanded=0)
D: 3392619 [DMG]3392625 [EME:25025r M:246969011 (Ack:195126046)] (S) Msg TX toportData 43048
D: 339645 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 3392650 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 3392657 [DMG]IM RH moving to [AwaitingDestruction]
D: 3392662 [DMG]All ReadHan] (U) Msg RX from 0:02A569D500F28ECD [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 3392681 [EM]Found matching exchange: 25024r, Delegate: (nil)
D: 3392687 [EM]Rxd Acmoving MessageCounter:141505748 from Retrans Table on exchange 25024r
I: 3392698 [EM]>>> [E:25025r M:19sg RX from 1:000000000001B669 [4F8F] --- Type 0000:10 ( 3392716 [EM]Rxd Ack; Removing MessageCounter:246969011 from Retrans Table on exchange 25025r
I: 3543055 [EM]>>> [E:5751r M:80229133] (U) Msg RX from 0:D63C19F7C9A9578D [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 3543066 [EM]Handling via exchange: 5751r, Delegate: 0x200042e0
I: 3543072 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 3543080 [IN]CASE Server disabling CASE session setups
I: 3543085 [EM]<<< [E:5751r M:141505749 (Ack:80229133)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 3543098 [IN](U) Sending msg 141505749 to IP address 'UDP:[fd09:9880:1c2b:fdb3:782a:fd75:649b:a29e]:47671'
D: 3543108 [EM]Flushed pending ack for MessageCounter:80229133 on exchange 5751r
I: 3543115 [SC]Received Sigma1 msg
D: 3543119 [SC]Found MRP parameters in the message
D: 3543124 [SC]Peer assigned session key ID 12730
I: 3543132 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 3543352 [SC]Including MRP parameters
I: 3543356 [EM]<<< [E:5751r M:141505750 (Ack:80229133)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 3543369 [IN](U) Sending msg 141505750 to IP address 'UDP:[fd09:9880:1c2b:fdb3:782a:fd75:649b:a29e]:47671'
I: 3543380 [SC]Sent Sigma2 msg
I: 3543520 [EM]>>> [E:5751r M:80229134 (Ack:141505750)] (U) Msg RX from 0:D63C19F7C9A9578D [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 3543532 [EM]Found matching exchange: 5751r, Delegate: 0x200042fc
D: 3543538 [EM]Rxd Ack; Removing MessageCounter:141505750 from Retrans Table on exchange 5751r
I: 3543547 [EM]<<< [E:5751r M:141505751 (Ack:80229134)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 3543559 [IN](U) Sending msg 141505751 to IP address 'UDP:[fd09:9880:1c2b:fdb3:782a:fd75:649b:a29e]:47671'
D: 3543570 [EM]Flushed pending ack for MessageCounter:80229134 on exchange 5751r
I: 3543577 [SC]Received Sigma3 msg
E: 3543585 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 3543861 [SC]Sending status report. Protocol code 0, exchange 5751
I: 3543867 [EM]<<< [E:5751r M:141505752 (Ack:80229134)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 3543880 [IN](U) Sending msg 141505752 to IP address 'UDP:[fd09:9880:1c2b:fdb3:782a:fd75:649b:a29e]:47671'
I: 3543892 [SC]SecureSession[0x20003a08]: Moving from state 'kEstablishing' --> 'kActive'
D: 3543900 [IN]SecureSession[0x20003a08]: Activated - Type:2 LSID:43049
D: 3543907 [IN]New secure session activated for device <000000000001B669, 1>, LSID:43049 PSID:12730!
I: 3543917 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 3543925 [IN]CASE Server enabling CASE session setups
D: 3543930 [IN]SecureSession[0x20003ac0]: Allocated Type:2 LSID:43050
D: 3543936 [SC]Allocated SecureSession (0x20003ac0) - waiting for Sigma1 msg
I: 3543944 [EM]>>> [E:5752r M:70066408] (S) Msg RX from 1:000000000001B669 [4F8F] --- Type 0001:02 (IM:ReadRequest)
D: 3543954 [EM]Handling via exchange: 5752r, Delegate: 0x2000d504
D: 3543960 [IM]Received Read request
D: 3543964 [DMG]IM RH moving to [GeneratingReports]
D: 3543969 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 3543978 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 3543983 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 3543992 [DMG]<RE> Sending report (payload has 37 bytes)...
I: 3543998 [EM]<<< [E:5752r M:105449205 (Ack:70066408)] (S) Msg TX to 1:000000000001B669 [4F8F] --- Type 0001:05 (IM:ReportData)
I: 3544010 [IN](S) Sending msg 105449205 on secure session with LSID: 43049
D: 3544017 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 3544022 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 3544030 [DMG]IM RH moving to [AwaitingDestruction]
D: 3544035 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 3544041 [EM]>>> [E:5751r M:80229135 (Ack:141505752)] (U) Msg RX from 0:D63C19F7C9A9578D [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 3544055 [EM]Found matching exchange: 5751r, Delegate: (nil)
D: 3544061 [EM]Rxd Ack; Removing MessageCounter:141505752 from Retrans Table on exchange 5751r
I: 3544070 [EM]>>> [E:5752r M:70066409 (Ack:105449205)] (S) Msg RX from 1:000000000001B669 [4F8F] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 3544083 [EM]Found matching exchange: 5752r, Delegate: (nil)
D: 3544089 [EM]Rxd Ack; Removing MessageCounter:105449205 from Retrans Table on exchange 5752r

I would like to know if this is intended behavior, and if not, how I could fix this issue to get a non-zero reading. Do let me know I need to upload any code! Thank you!

Parents
  • 0

    Hi,

    I've had a look at your case and I think I need some more information to be able to isolate the issue. It seems to me that you're following the guide correctly based on your description of how you've done it, but just to be sure: did you activate the sensor by sending a On command?

    In addition, could you supply us a log that shows all of the chip-tool commands you send and the logs following for us to have a look at?

    Kind regards,
    Andreas

  • 0 in reply to AHaug

    Hey Andreas,

    Thank you for reaching out!

    Attached below is a log of the chip-tool commands that I have used:

    The corresponding logs are as shown below::

    Fullscreen 7840.screenlog.txt Download 
    I: 62205 [DL]BLE connection established (ConnId: 0x00)
I: 62210 [DL]Current number of connections: 1/2
I: 62215 [DL]CHIPoBLE advertising stopped
D: 63946 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 63953 [BLE]local and remote recv window sizes = 5
I: 63958 [BLE]selected BTP version 4
I: 63961 [BLE]using BTP fragment sizes rx 244 / tx 244.
D: 64046 [DL]ConnId: 0x00, New CCCD value: 0x0002
D: 64050 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
D: 64058 [IN]BLE EndPoint 0x2000fb38 Connection Complete
I: 64063 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
D: 64146 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 64196 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 64203 [EM]>>> [E:52204r M:107477544] (U) Msg RX from 0:5A64DAEF41C06E17 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
D: 64215 [EM]Handling via exchange: 52204r, Delegate: 0x20005854
I: Event put resultsion ID 36366
D: 64236 [SC]Found MRP parameters in the message
D: 64240 [SC]RP parameters iram reM]<<< [E:52204r M:68046746] (U) Msg 0 [0000nnel:PBKDFParamResponse)
I: 64258 [IN]Sending indication foId 00, len 140)
D: 64271  PBKDFm resD~~~~~~~~~~~~~~~~
D: Curre346 [DL]Indication for CHIPoBLE TX characte(ConnId 0x00, result 0x096 [, Delegat: 0x264420 [C]Receed spae2p msg1
 0
I: 66408 [EM]<<< [E:52204r M:68046747] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
I: 66419 [IN](U) Sending msg 68046747 to IP address 'BLE'
D: 66424 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132)
D: 66431 [SC]Sent spake2p msg2
E: 66434 [DL]Long dispatch time: 2038 ms, for event type 16388
D: Current evenD: 66496 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 66504 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 66512 [EM]>>> [E:52204r M:107477546] (U) Msg RX from 0:5A64DAEF41C06E17 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
D: 66523 [EM]Found matching exchange: 52204r, Delegate: 0x20005854
D: 66529 [SC]Received spake2p msg3
D: 66532 [SC]Sending status report. Protocol code 0, exchange 52204
I: 66539 [EM]<<< [E:52204r M:68046748] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 66557 [IN](U) Sending msg 68046748 to IP address 'BLE'
D: 66562 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35)
I: 66571 [SC]SecureSession[0x20003670]: Moving from state 'kEstablishing' --> 'kActive'
D: 66578 [IN]SecureSession[0x20003670]: Activated - Type:1 LSID:27628
D: 66585 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:27628 PSID:36366!
I: 66593 [SVR]Commissioning completed session establishment step
I: 66600 [DIS]Updating services using commissioning mode 0
D: 66605 [DL]Using Thread extended MAC for hostname.
D: 66610 [DL]Using Thread extended MAC for hostname.
I: 66615 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=0
E: 66624 [DIS]Failed to advertise extended commissionable node: 3
D: 66630 [DIS]Scheduling extended discovery timeout in 900s
E: 66635 [DIS]Failed to finalize service update: 1c
D: 66640 [DL]CHIPoBLE advertising set to off
I: 66644 [SVR]Device completed Rendezvous process
E: 66649 [DL]Long dispatch time: 145 ms, for event type 16388
D: 66655 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 66698 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 66706 [EM]>>> [E:52205r M:50828103] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 66716 [EM]Handling via exchange: 52205r, Delegate: 0x2000d504
D: 66722 [IM]Received Read request
D: 66728 [DMG]IM RH moving to [GeneratingReports]
D: 66733 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 66741 [DMG]<RE:Run> Cluster 31, Attribute 3 is dirty
D: 66746 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1)
D: 66755 [DMG]<RE:Run> Cluster 28, Attribute 4 is dirty
D: 66760 [DMG]Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0)
D: 66777 [D [DMG]<RE:Run> Cluster 30, Attribute 3 is dirty
D: 66796 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0)
D: 66805 [DMG]<RE:Run> Cluster 30, Attribute 2 is dirty
D: 66810 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0)
D: 66819 [DMG]<RE:Run> Cluster 30, Attribute 1 is dirty
D: 66824 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0)
D: 66833 [DMG]<RE:Run> Cluster 30, Attribute 0 is dirty
D: 66838 [DMG]Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0)
D: 66847 [DMG]<RE:Run> Cluster 31, Attribute fffc is dirty
D: 66852 [DMG]Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1)
D: 66861 [DMG]<RE> Sending report (payload has 228 bytes)...
I: 66868 [EM]<<< [E:52205r M:129127597] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 66886 [IN](S) Sending msg 129127597 on secure session with LSID: 27628
D: 66892 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 66900 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 66904 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 66912 [DMG]IM RH moving to [AwaitingDestruction]
D: 66916 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
D: 66996 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 67003 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 21)
D: 67097 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 67146 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 67154 [EM]>>> [E:52206r M:50828104] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 67165 [EM]Handling via exchange: 52206r, Delegate: 0x2000d504
D: 67172 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
I: 67179 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
D: 67185 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1a131e70
D: 67191 [DMG]Command handler moving to [ Preparing]
D: 67203 [DMG]Command handler moving to [AddingComm]
D: 67208 [DMG]Command handler moving to [AddedComma]
D: 67213 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 67220 [EM]<<< [E:52206r M:129127598] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 67231 [IN](S) Sending msg 129127598 on secure session with LSID: 27628
D: 67238 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 67246 [DMG]Command handler moving to [CommandSen]
D: 67251 [DMG]Command handler moving to [AwaitingDe]
E: 67255 [DL]Long dispatch time: 109 ms, for event type 16388
D: 67446 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 67496 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 67504 [EM]>>> [E:52207r M:50828105] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 67528 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002
D: 67554 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1a131e71
D: 67560 [DMG]Command handler moving to [ Preparing]
D: 67565 [DMG]Command handler moving to [AddingComm]
D: 67569 [DMG]Command handler moving to [AddedComma]
D: 67574 asing reference count for CommandHandler, remaining 0
I: 67581 [EM]<<< [E:52207r M:129127599] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 67592 [IN](S) Sending msg 129127599 on secure session with LSID: 27628
D: 67599 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 67606 [DMG]Command handler moving to [CommandSen]
D: 67611 [DMG]Command handler moving to [AwaitingDe]
E: 67616 [DL]Long dispatch time: 120 ms, for event type 16388
D: 67666 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 67674 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 67682 [EM]>>> [E:52208r M:50828106] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type : 52208r, Delegate: 0x2000d504
D: 67700 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
I: 67707 [ZCL]OpCreds: Certificate Chain request received for PAI
D: 67713 [DMG]Command handler moving to [ Preparing]
D: 67718 [DMG]Command handler moving to [AddingComm]
D: 67723 [DMG]Command handler moving to [AddedComma]
D: 67735 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 67744 [EM]<<< [E:52208r M:129127600] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 67755 [IN](S) Sending msg 129127600 on secure session with LSID: 27628
D: 67762 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 67770 [DMG]Command handler moving to [CommandSen]
D: 67774 [DMG]Command handler moving to [AwaitingDe]
E: 67779 [DL]Long dispatch time: 105 ms, for event type 16388
D: 67846 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 67853 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 67936 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 67951 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48)
D: 68026 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 68034 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 68042 [EM]>>> [E:52209r M:50828107] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 68061 [EM]Handling via exchange: 52209r, Delegate: 0x2000d504
D: 68067 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
I: 68075 [ZCL]OpCreds: Certificate Chain request received for DAC
D: 68080 [DMG]Command handler moving to [ Preparing]
D: 68085 [DMG]Command handler moving to [AddingComm]
D: 68090 [DMG]Command handler moving to [AddedComma]
D: 68095 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 68104 [EM]<<< [E:52209r M:129127601] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 68115 [IN](S) Sending msg 129127601 on secure session with LSID: 27628
D: 68122 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 68130 [DMG]Command handler moving to [CommandSen]
D: 68134 [DMG]Command handler moving to [AwaitingDe]
E: 68139 [DL]Long dispatch time: 105 ms, for event type 16388
D: 68206 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 68213 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 68296 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 68303 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 78)
D: 68386 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 68431 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 68439 [EM]>>> [E:52210r M:50828108] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 68450 [EM]Handling via exchange: 52210r, Delegate: 0x2000d504
D: 68456 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000
I: 68464 [ZCL]OpCreds: Received an AttestationRequest command
I: 68508 [ZCL]OpCreds: AttestationRequest successful.
D: 68512 [DMG]Command handler moving to [ Preparing]
D: 68517 [DMG]Command handler moving to [AddingComm]
D: 68522 [DMG]Command handler moving to [AddedComma]
D: 68527 [DMG]Decreasing reference count for CommandHandler, remaining 0
I:0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 68548 [IN](S) Sending msg 129127602 on secure session with LSID: 27628
D: 68554 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 68562 [DMG]Command handler moving to [CommandSen]
D: 68567 [DMG]Command handler moving to [AwaitingDe]
E: 68572 [DL]Long dispatch time: 141 ms, for event type 16388
D: 68611 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 68618 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 68701 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 68708 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 235)
D: 68791 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 68836 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 68844 [EM]>>> [E:52211r M:50828109] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 68855 [EM]Handling via exchange: 52211r, Delegate: 0x2000d504
D: 68861 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004
I: 68869 [ZCL]OpCreds: Received a CSRRequest command
D: 68873 [ZCL]OpCreds: Finding fabric with fabricIndex 0x0
I: 69078 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
I: 69114 [ZCL]OpCreds: CSRRequest successful.
D: 69125 [DMG]Command handler moving to [ Preparing]
D: 69130 [DMG]Command handler moving to [AddingComm]
D: 69135 [DMG]Command handler moving to [AddedComma]
D: 69140 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 69148 [EM]<<< [E:52211r M:129127603] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 69159 [IN](S) Sending msg 129127603 on secure session with LSID: 27628
D: 69166 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 69173 [DMG]Command handler moving to [CommandSen]
D: 69178 [DMG]Command handler moving to [AwaitingDe]
E: 69183 [DL]Long dispatch time: 347 ms, for event type 16388
D: 69241 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 69248 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 139)
D: 69337 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 69381 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 69467 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 69476 [EM]>>> [E:52212r M:50828110] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 69487 [EM]Handling via exchange: 52212r, Delegate: 0x2000d504
D: 69493 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B
I: 69501 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
I: 69572 [ZCL]OpCreds: AddTrustedRootCertificate successful.
D: 69577 [DMG]Command handler moving to [ Preparing]
D: 69582 [DMG]Command handler moving to [AddingComm]
D: 69586 [DMG]Command handler moving to [AddedComma]
D: 69591 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 69598 [EM]<<< [E:52212r M:129127604] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 69609 [IN](S) Sending msg 129127604 on secure session with LSID: 27628
D: 69616 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
D: 69624 [DMG]Command handler moving to [CommandSen]
D: 69628 [DMG]Command handler moving to [AwaitingDe]
E: 69633 [DL]Long dispatch time: 166 ms, for event type 16388
D: 69691 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 69740 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 69832 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 69918 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 69928 [EM]>>> [E:52213r M:50828111] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 69939 [EM]Handling via exchange: 52213r, Delegate: 0x2000d504
D: 69945 [DMG]Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006
I: 69953 [ZCL]OpCreds: Received an AddNOC command
I: 69959 [FP]Validating NOC chain
I: 70092 [FP]NOC chain validation successful
I: 70096 [FP]Added new fabric at index: 0x1
I: 70100 [FP]Assigned compressed fabric ID: 0x803DA129E34B9AE9, node ID: 0x0000000000000001
I: 70108 [TS]Last Known Good Time: 2023-01-05T01:05:04
I: 70113 [TS]New proposed [DMG]Ete version to 9b12f55c
D: 70130 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 9b12f55d
D: 70160 [EVL]LogEvent event number: 0x0000000000000003 priority: 1, endpoint id:  0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x0000000000011210
I: 70182 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669
D: 70190 [DL]Using Thread extended MAC for hostname.
I: 70195 [DIS]Advertise operational node 803DA129E34B9AE9-0000000000000001
D: 70202 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 9b12f55e
D: 70208 [DMG]Endpoint 0, Cluster 0x0000_003E update version to 9b12f55f
D: 70215 [DMG]Command handler moving to [ Preparing]
D: 70220 [DMG]Command handler moving to [AddingComm]
D: 70224 [DMG]Command handler moving to [AddedComma]
I: 70229 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC
D: 70236 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 70243 [EM]<<< [E:52213r M:129127605] (S) Msg TX to 1:FFFFFFFB00000000 [9AE9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 70254 [IN](S) Sending msg 129127605 on secure session with LSID: 27628
D: 70260 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 70268 [DMG]Command handler moving to [CommandSen]
D: 70273 [DMG]Command handler moving to [AwaitingDe]
E: 70278 [DL]Long dispatch time: 359 ms, for event type 16388
D: 70321 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 70368 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 70376 [EM]>>> [E:52214r M:50828112] (S) Msg RX from 1:FFFFFFFB00000000 [9AE9] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 70387 [EM]Handling via exchange: 52214r, Delegate: 0x2000d504
D: 70401 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003
D: 70415 [DMG]Command handler moving to [ Preparing]
D: 70420 [DMG]Command handler moving to [AddingComm]
D: 70424 [DMG]Command handler moving to [AddedComma]
D: 70429 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1a131e72
D: 70436 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 70443 [EM]<<< [E:52214r M:129127606] (S) Msg TX to 1:FFFFFFFB00000000 [9AE9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 70454 [IN](S) Sending msg 129127606 on secure session with LSID: 27628
D: 70461 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 70468 [DMG]Command handler moving to [CommandSen]
D: 70473 [DMG]Command handler moving to [AwaitingDe]
E: 70478 [DL]Long dispatch time: 110 ms, for event type 16388
D: 70546 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 70591 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 70599 [EM]>>> [E:52215r M:50828113] (S) Msg RX from 1:FFFFFFFB00000000 [9AE9] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 70617 [EM]Handling via exchange: 52215r, Delegate: 0x2000d504
D: 70623 [DMG]Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006
D: 70645 [DMG]Decreasing reference count for CommandHandler, remaining 1
D: 70651 [DL]OpenThread State Changed (Flags: 0x1017c100)
D: 70656 [DL]   Network Name: OpenThread-417e
D: 70660 [DL]   PAN Id: 0x417E
D: 70663 [DL]   Extended PAN Id: 0x59DF98EF8E4B2554
D: 70668 [DL]   Channel: 15
D: 70670 [DL]   Mesh Prefix: fd94:2a4b:9949:167a::/64
D: 70676 [DL]OpenThread State Changed (Flags: 0x1100101d)
D: 70682 [DL]   Device Role: DETACHED
D: 70685 [DL]   Thread Unicast Addresses:
D: 70689 [DL]        fd94:2a4b:9949:167a:1cb2:7692:2d78:5ca/64 valid
D: 70695 [DL]        fe80::ec19:207e:811:7115/64 valid preferred
~~~~~~~~~~~[~~~~~~I: 72689 [DL]SRP Client was started, detecte9:167a:715e:3fee:64f9:f: 72698 [DL]Od (Flags: 0x200002a4)
D: 72703 [DL]   Device Role: CHILD
D: 727rtition IdDL]OpenThread State Cha 0x00000001bb:4895:d684D: 72884 [DL]   fd94:2a4b]        fd7692:2d78:5c[DL]Long dis 276 ms, for 32777
D: 72994 [DMG]Command handler moving to [ Preparing]
D: 73mand handler moving to [AddingComm]
D: 73005 [Dandler movoint 0, C15r M607] (S)o 1:FFFFFFFB00000000 [9AE9] --- Type 0001:09 (IM:Invo) Sending mson with LSI73045 [DL]dication PoBLE Tcteristic (ConnId 00, len 70en]
D: 73mand   itingD Thread extended MAC for hostname.
I: 73067 [DIS]Advertise operational node 803DA129E34B9AE9-0000000000000001
3074 [SVR]Opeing enled
D: 73111 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 73122 [ds
I: 73143 [DIS]Updating services using commissioning mode 0
D: 73148 [DL]Using Thread extended MAC for hostname.
I: 731530000001._matter._tcp
D: 73168 [DL]Using Thread stname.
I: 73174se commdorID=65521 produc840/15 cm=0
I: 73183 [update 
D: 73196 [DMG]Endpoint 0, Cluster 0x0000_002A u2I: 74603 [EM]>>> [E:52216r M:107477547] (U) Msg RX from 0:360ED5332200EFE4 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 74614 [EM]Handling via exchange: 52216r, Delegate: 0x200042e0
I: 74620 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 74627 [IN]CASE Server disabling CASE session setups
I: 74632 [EM]<<< [E:52216r M:68046749 (Ack:107477547)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 74645 [IN](U) Sending msg 68046749 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:35432'
D: 74656 [EM]Flushed pending ack for MessageCounter:107477547 on exchange 52216r
I: 74663 [SC]Received Sigma1 msg
D: 74666 [SC]Found MRP parameters in the message
D: 74671 [SC]Peer assigned session key ID 36367
I: 74678 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 74899 [SC]Including MRP parameters
I: 74904 [EM]<<< [E:52216r M:68046750 (Ack:107477547)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 74916 [IN](U) Sending msg 68046750 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:35432'
I: 74927 [SC]Sent Sigma2 msg
I: 75064 [EM]>>> [E:52216r M:107477548 (Ack:68046750)] (U) Msg RX from 0:360ED5332200EFE4 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 75076 [EM]Found matching exchange: 52216r, Delegate: 0x200042fc
D: 75082 [EM]Rxd Ack; Removing MessageCounter:68046750 from Retrans Table on exchange 52216r
I: 75091 [EM]<<< [E:52216r M:68046751 (Ack:107477548)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 75104 [IN](U) Sending msg 68046751 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:35432'
D: 75114 [EM]Flushed pending ack for MessageCounter:107477548 on exchange 52216r
I: 75122 [SC]Received Sigma3 msg
E: 75129 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 75486 [SC]Sending status report. Protocol code 0, exchange 52216
I: 75492 [EM]<<< [E:52216r M:68046752 (Ack:107477548)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 75505 [IN](U) Sending msg 68046752 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:35432'
I: 75516 [SC]SecureSession[0x20003728]: Moving from state 'kEstablishing' --> 'kActive'
D: 75524 [IN]SecureSession[0x20003728]: Activated - Type:2 LSID:27629
D: 75531 [IN]New secure session activated for device <000000000001B669, 1>, LSID:27629 PSID:36367!
I: 75540 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 75546 [IN]CASE Server enabling CASE session setups
D: 75551 [IN]SecureSession[0x200037e0]: Allocated Type:2 LSID:27630
D: 75558 [SC]Allocated SecureSession (0x200037e0) - waiting for Sigma1 msg
D: 75631 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 75755 [EM]>>> [E:52217r M:5096672] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 75768 [EM]Handling via exchange: 52217r, Delegate: 0x2000d504
D: 75774 [DMG]Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004
I: 75781 [FS]GeneralCommissioning: Received CommissioningComplete
I: 75891 [FP]Metadata for Fabric 0x1 persisted to storage.
I: 76116 [TS]Committing Last Known Good Time to storage: 2023-01-05T01:05:04
I: 76199 [ZCL]OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x803DA129E34B9AE9, FabricId 0000000000000001, NodeId 0000000000000001, VendorId 0xFFF1
I: 76242 [FS]GeneralCommissioning: Successfully commited pending fabric data
I: 76249 [FS]Fail-safe cleanly disarmed
D: 76253 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to 1a131e74
D: 76260 [DMG]Command handler moving to [ Preparing]
D: 76264 [DMG]Command handler moving to [AddingComm]
D: 76269 [DMG]Command handler moving to [AddedComma]
D: 76274 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 76281 [EM]<<< [E:52217r M:130316526 (Ack:5096672)] (S) Msg TX to 1:000000000001B669 [9AE9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 76293 [IN](S) Sending msg 130316526 on secure session with LSID: 27629
D: 76301 [DMG]Command handler moving to [CommandSen]
D: 76306 [DMG]Command handler moving to [AwaitingDe]
I: 76311 [SWU]Device commissioned, schedule a default provider query
I: 76317 [SVR]Commissioning completed successfully
I: 76322 [DIS]Updating services using commissioning mode 0
D: 76329 [DL]Using Thread extended MAC for hostname.
I: 76334 [DIS]Advertise operational node 803DA129E34B9AE9-0000000000000001
D: 76341 [DL]Using Thread extended MAC for hostname.
I: 76347 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=0
D: 76359 [IN]Expiring all PASE sessions
D: 76363 [IN]SecureSession[0x20003670]: MarkForEviction Ty 76369 [SC]SecureSession[0x20003670]: Moving from state 'kActive' --> 'kPendingEviction'
D: 76377 [IN]SecureSession[0x20003670]: Released - Type:1 LSID:27628
D: 76383 [IN]Clearing BLE pending packets.
I: 76387 [BLE]Releasing end point's BLE connection back to application.
I: 76393 [DL]Closing BLE GATT connection (ConnId 00)
D: 76399 [ZCL]Commissioning complete, notify platform driver to persist network credentials.
E: 76441 [DL]Long dispatch time: 130 ms, for event type 32781
D: 76446 [DL]ConnId: 0x00, New CCCD value: 0x0000
E: 76451 [BLE]no endpoint for unsub recvd
D: 76455 [EM]Retransmitting MessageCounter:68046752 on exchange 52216r Send Cnt 1
I: 76462 [IN](U) Sending msg 68046752 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:35432'
I: 76473 [EM]>>> [E:52216r M:107477549 (Ack:68046752)] (U) Msg RX from 0:360ED5332200EFE4 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 76486 [EM]Found matching exchange: 52216r, Delegate: (nil)
D: 76492 [EM]Rxd Ack; Removing MessageCounter:68046752 from Retrans Table on exchange 52216r
D: 76501 [IN]Received a duplicate message with MessageCounter:5096672 on exchange 52217r
I: 76511 [EM]>>> [E:52217r M:5096672] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 76523 [EM]Found matching exchange: 52217r, Delegate: (nil)
D: 76528 [EM]Forcing tx of solitary ack for duplicate MessageCounter:5096672 on exchange 52217r
I: 76538 [EM]<<< [E:52217r M:130316527 (Ack:5096672)] (S) Msg TX to 1:000000000001B669 [9AE9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 76550 [IN](S) Sending msg 130316527 on secure session with LSID: 27629
I: 76557 [DL]BLE GAP connection terminated (reason 0x16)
I: 76563 [DL]Current number of connections: 0/2
D: 76568 [IN]Received a duplicate message with MessageCounter:5096672 on exchange 52217r
I: 76576 [EM]>>> [E:52217r M:5096672] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 76589 [EM]Found matching exchange: 52217r, Delegate: (nil)
D: 76595 [EM]Forcing tx of solitary ack for duplicate MessageCounter:5096672 on exchange 52217r
I: 76604 [EM]<<< [E:52217r M:130316528 (Ack:5096672)] (S) Msg TX to 1:000000000001B669 [9AE9] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 76617 [IN](S) Sending msg 130316528 on secure session with LSID: 27629
I: 76625 [EM]>>> [E:52217r M:5096673 (Ack:130316526)] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 76638 [EM]Found matching exchange: 52217r, Delegate: (nil)
D: 76644 [EM]Rxd Ack; Removing MessageCounter:130316526 from Retrans Table on exchange 52217r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~E: 106317 [SWU]No suitable OTA Provider candidate found
I: 106322 [SWU]No provider available
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~1D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: 210016 [EM]>>> [E:35824r M:23453654] (U) Msg RX from 0:B7A9B0155C49CDF5 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 210027 [EM]Handling via exchange: 35824r, Delegate: 0x200042e0
I: 210033 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 210041 [IN]CASE Server disabling CASE session setups
I: 210046 [EM]<<< [E:35824r M:68046753 (Ack:23453654)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 210059 [IN](U) Sending msg 68046753 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:45986'
D: 210069 [EM]Flushed pending ack for MessageCounter:23453654 on exchange 35824r
I: 210076 [SC]Received Sigma1 msg
D: 210079 [SC]Found MRP parameters in the message
D: 210084 [SC]Peer assigned session key ID 45826
I: 210092 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 210313 [SC]Including MRP parameters
I: 210317 [EM]<<< [E:35824r M:68046754 (Ack:23453654)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 210329 [IN](U) Sending msg 68046754 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:45986'
I: 210340 [SC]Sent Sigma2 msg
I: 210462 [EM]>>> [E:35824r M:23453655 (Ack:68046754)] (U) Msg RX from 0:B7A9B0155C49CDF5 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 210474 [EM]Found matching exchange: 35824r, Delegate: 0x200042fc
D: 210480 [EM]Rxd Ack; Removing MessageCounter:68046754 from Retrans Table on exchange 35824r
I: 210489 [EM]<<< [E:35824r M:68046755 (Ack:23453655)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 210501 [IN](U) Sending msg 68046755 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:45986'
D: 210512 [EM]Flushed pending ack for MessageCounter:23453655 on exchange 35824r
I: 210519 [SC]Received Sigma3 msg
E: 210526 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 210810 [SC]Sending status report. Protocol code 0, exchange 35824
I: 210817 [EM]<<< [E:35824r M:68046756 (Ack:23453655)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 210829 [IN](U) Sending msg 68046756 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:45986'
I: 210840 [SC]SecureSession[0x200037e0]: Moving from state 'kEstablishing' --> 'kActive'
D: 210848 [IN]SecureSession[0x200037e0]: Activated - Type:2 LSID:27630
D: 210855 [IN]New secure session activated for device <000000000001B669, 1>, LSID:27630 PSID:45826!
I: 210864 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 210870 [IN]CASE Server enabling CASE session setups
D: 210875 [IN]SecureSession[0x20003670]: Allocated Type:2 LSID:27631
D: 210882 [SC]Allocated SecureSession (0x20003670) - waiting for Sigma1 msg
I: 210896 [EM]>>> [E:35825r M:80756641] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 210908 [EM]Handling via exchange: 35825r, Delegate: 0x2000d504
D: 210915 [DMG]Received command for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0001
I: 210923 [ZCL]On/Off set value: 1 1
I: 210926 [ZCL]Toggle on/off from 0 to 1
D: 210930 [DMG]Endpoint 1, Cluster 0x0000_0006 update version to e38d2c11
D: 210936 [DMG]Command handler moving to [ Preparing]
D: 210941 [DMG]Command handler moving to [AddingComm]
D: 210946 [DMG]Command handler moving to [AddedComma]
D: 210951 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 210958 [EM]<<< [E:35825r M:236066413 (Ack:80756641)] (S) Msg TX to 1:000000000001B669 [9AE9] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 210970 [IN](S) Sending msg 236066413 on secure session with LSID: 27630
D: 210978 [DMG]Command handler moving to [CommandSen]
D: 210983 [DMG]Command handler moving to [AwaitingDe]
I: 210989 [EM]>>> [E:35824r M:23453656 (Ack:68046756)] (U) Msg RX from 0:B7A9B0155C49CDF5 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 211001 [EM]Found matching exchange: 35824r, Delegate: (nil)
D: 211007 [EM]Rxd Ack; Removing MessageCounter:68046756 from Retrans Table on exchange 35824r
I: 211025 [EM]>>> [E:35825r M:80756642 (Ack:236066413)] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 211037 [EM]Found matching exchange: 35825r, Delegate: (nil)
D: 211043 [EM]Rxd Ack; Removing MessageCounter:236066413 from Retrans Table on exchange 35825r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~51D~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: r M:164812137] (U) Msg RX from 0:90B6AA8011880E24 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 232212 [EM]Handling via exchange: 65009r, Delegate: 0x200042e0
I: 232218 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 232225 [IN]CASE Server disabling CASE session setups
I: 232231 [EM]<<< [E:65009r M:000000 [000e 0000:10 (Sek)
I: 2322U) Sendo IP aress 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:54012'
D: 232253 [EM]Flus MesageCountern exchange  232261 [SCigma1 msg
[SC]Found MRP parameters in the messagCned session key ID 1598I: 232277 [SCeon ID: fabrN00000000000D: 232497 [S[reChannel:CASE_Sigma2)
I: 22514 [IN](U) Sending msg 68046758 to DP:[fd58:ef8e:2554:788f:683d:92d:9444]:54012'
524 [SC]Sent Sigma2 msg
I: 232647 [EM]>>> [E:65009r M:164812138 (Ack:68046758)] (U) Msg RX from 0:90B6AA8011880E24 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 232660 [EM]Found matching exchange: 65009r, Delegate: 0x200042fc
D: 232666 [EM]Rxd Ack; Removing MessageCounter:68046758 from Retrans Table on exchange 65009r
I: 232675 [EM]<<< [E:65009r M:68046759 (Ack:164812138)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 232687 [IN](U) Sending msg 68046759 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:54012'
D: 232697 [EM]Flushed pending ack for MessageCounter:164812138 on exchange 65009r
I: 232705 [SC]Received Sigma3 msg
E: 232712 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 232987 [SC]Sending status report. Protocol code 0, exchange 65009
I: 232994 [EM]<<< [E:65009r M:68046760 (Ack:164812138)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 233006 [IN](U) Sending msg 68046760 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:54012'
I: 233018 [SC]SecureSession[0x20003670]: Moving from state 'kEstablishing' --> 'kActive'
D: 233026 [IN]SecureSession[0x20003670]: Activated - Type:2 LSID:27631
D: 233032 [IN]New secure session activated for device <000000000001B669, 1>, LSID:27631 PSID:15984!
I: 233041 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 233047 [IN]CASE Server enabling CASE session setups
D: 233053 [IN]SecureSession[0x20003898]: Allocated Type:2 LSID:27632
D: 233059 [SC]Allocated SecureSession (0x20003898) - waiting for Sigma1 msg
I: 233091 [EM]>>> [E:65010r M:191809915] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0001:02 (IM:ReadRequest)
D: 233103 [EM]Handling via exchange: 65010r, Delegate: 0x2000d504
D: 233109 [IM]Received Read request
D: 233113 [DMG]IM RH moving to [GeneratingReports]
D: 233117 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 233126 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 233131 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 233140 [DMG]<RE> Sending report (payload has 37 bytes)...
I: 233146 [EM]<<< [E:65010r M:101818775 (Ack:191809915)] (S) Msg TX to 1:000000000001B669 [9AE9] --- Type 0001:05 (IM:ReportData)
I: 233158 [IN](S) Sending msg 101818775 on secure session with LSID: 27631
D: 233165 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 233170 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 233178 [DMG]IM RH moving to [AwaitingDestruction]
D: 233183 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 233189 [EM]>>> [E:65009r M:164812139 (Ack:68046760)] (U) Msg RX from 0:90B6AA8011880E24 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 233203 [EM]Found matching exchange: 65009r, Delegate: (nil)
D: 233209 [EM]Rxd Ack; Removing MessageCounter:68046760 from Retrans Table on exchange 65009r
I: 233218 [EM]>>> [E:65010r M:191809916 (Ack:101818775)] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 233231 [EM]Found matching exchange: 65010r, Delegate: (nil)
D: 233237 [EM]Rxd Ack; Removing MessageCounter:101818775 from Retrans Table on exchange 65010r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: 293073 [EM]>>> [E:51664r M:47589619] (U) Msg RX from 0:161F008417CD4949 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 293084 [EM]Handling via exchange: 51664r, Delegate: 0x200042e0
I: 293090 [IN]CASE Server received Sigma1 message. Starting disabling CASE session setups
I: 293103 [EM]<<< [E:51664r M:68046761 (Ack:47589619)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 293115 [IN](U) Sending msg 68046761 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:34009'
D: 293126 [EM]Flushed pending ack for MessageCounter:47589619 on exchange 51664r
I: 293133 [SC]Received Sigma1 msg
D: 293136 [SC]Found MRP parameters in the message
D: 293141 [SC]Peer assigned session key ID 43507
I: 293149 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 293368 [SC]Including MRP parameters
I: 293372 [EM]<<< [E:51664r M:68046762 (Ack:47589619)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 293385 [IN](U) Sending msg 68046762 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:34009'
I: 293396 [SC]Sent Sigma2 msg
I: 293523 [EM]>>> [E:51664r M:47589620 (Ack:68046762)] (U) Msg RX from 0:161F008417CD4949 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 293536 [EM]Found matching exchange: 51664r, Delegate: 0x200042fc
D: 293542 [EM]Rxd Ack; Removing MessageCounter:68046762 from Retrans Table on exchange 51664r
I: 293550 [EM]<<< [E:51664r M:68046763 (Ack:47589620)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 93563 [IN](U) Sending msg 68046763 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:34009'
D: 293573 [EM]Flushed pending ack for MessageCounter:47589620 on exchange 51664r
I: 293581 [SC]Received Sigma3 msg
E: 293588 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 293865 [SC]Sending status report. Protocol code 0, exchange 51664
I: 293871 [EM]<<< [E:51664r M:68046764 (Ack:47589620)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 293884 [IN](U) Sending msg 68046764 to IP address 'UDP:[fd59:df98:ef8e:2554:788f:683d:92d:9444]:34009'
I: 293895 [SC]SecureSession[0x20003898]: Moving from state 'kEstablishing' --> 'kActive'
D: 293903 [IN]SecureSession[0x20003898]: Activated - Type:2 LSID:27632
D: 293910 [IN]New secure session activated for device <000000000001B669, 1>, LSID:27632 PSID:43507!
I: 293919 [IN]CASE Session established to peer: <00000000I: 294041 [EM]>>> [E:51665r M:123628501] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0001:02 (IM:ReadRequest)
D: 294053 [EM]Handling via exchange: 51665r, Delegate: 0x2000d504
D: 294059 [IM]Received Read request
D: 294063 [DMG]IM RH moving to [GeneratingReports]
D: 294067 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 294076 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 294081 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 294090 [DMG]<RE> Sending report (payload has 37 bytes)...
I: 294096 [EM]<<< [E:51665r M:231159614 (Ack:123628501)] (S) Msg TX to 1:000000000001B669 [9AE9] --- Type 0001:05 (IM:ReportData)
I: 294108 [IN](S) Sending msg 231159614 on secure session with LSID: 27632
D: 294116 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 294120 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 294128 [DMG]IM RH moving to [AwaitingDestruction]
D: 294133 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 294139 [EM]>>> [E:51664r M:47589621 (Ack:68046764)] (U) Msg RX from 0:161F008417CD4949 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 294153 [EM]Found matching exchange: 51664r, Delegate: (nil)
D: 294159 [EM]Rxd Ack; Removing MessageCounter:68046764 from Retrans Table on exchange 51664r
I: 294168 [EM]>>> [E:51665r M:123628502 (Ack:231159614)] (S) Msg RX from 1:000000000001B669 [9AE9] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 294181 [EM]Found matching exchange: 51665r, Delegate: (nil)
D: 294187 [EM]Rxd Ack; Removing MessageCounter:231159614 from Retrans Table on exchange 51665r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[~~~~~~~~~~~~~~~~~~~~~~~A~~~~~~~~~~~~~~~~[1~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

    Here is the link to the repository for the code I have done up so far if it helps! Thank you!

    Side note: Where should I start looking if I would like to send commands remotely and not directly connected to a Wifi router? I have tried looking at this tutorial: openthread.io/.../openthread-border-router-nat64 but it does not seem to address my concerns about connecting to a Matter device! I think pointing me towards the right tutorial would be sufficient! Let me know if I should open another ticket for this!

  • 0 in reply to kendrik-dev

    Hi,

    We're still working on your case, but its taking a bit longer than expected to test and reproduce the sample. So just to keep the ball rolling on your end in the meanwhile, have you had any more luck in progressing the development?

    How do you set the temperature? Do you at any time call something like zapsomething_update_cluster(&tmp)? If you don't set the temperature at any point there shouldn't be any reason for you to not get the value 0 when you try to read the temperature value

    Did you manage to complete the entire guide? I'm assuming yes as you're sending the commands written in the last few steps of the guide

    Kind regards,
    Andreas

  • 0 in reply to AHaug

    Hey Andreas,

    I was looking through my code in this repo: https://github.com/justanotherkendrik/matter-sensor-example (I created a public repo here to hopefully make it easier to work with), and I do not see anything of that sort... Could making changes in `template.zap` cause this issue though?

  • 0 in reply to kendrik-dev

    Thank you for sharing. We're still lagging behind on possibility to recreate the sample due to some internal delay... I will ask around if any of my colleagues have the oportunity to handle the case for me while I'm OoO until next week. If not, then we will unfortunately have to wait for a hardware solution..

    Kind regards,
    Andreas

  • 0 in reply to kendrik-dev

    Hi, 

    Please try to delete "uint8_t mask," in the function MatterPostAttributeChangeCallback. This argument should not be included.

    Best regards,

    Charlie

Reply Children
  • 0 in reply to Charlie

    Oh hey, that worked! Thank you very much for reaching out! "uint8_t mask" was provided in the example given in the walkthrough, so I didn't think it could be that! I'm getting whole numbers populated in the measured values now (this seems like the correct output we should be getting)! The screenlog is available below:

    Fullscreen 6747.screenlog.txt Download 
    I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 621196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa21a
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 621696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa21b
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 622196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa21c
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 622696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa21d
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 623196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa21e
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 623696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa21f
D: Current event: 8
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 8
I: Event type: 8
~~~~~~~~~~~~~~G]Endpoint 1, Cluster 0x0000_0402 update version to 819fa220
D: Current event: 8
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: Event ut result: 0
D: Event  624696 [DMG0
D: Event in queue: 8
I: Event type: 8
D: 625196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa222
D: Current event: 8
I: Event pin queu 625696 [DMG0000_0402 u23
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 626196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa224
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 626696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa225
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 627196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa226
D: Current event: 8
I: 627357 [EM]>>> [E:36460r M:194927176] (U) Msg RX from 0:DEF17CDE5AF763F3 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 627369 [EM]Handling via exchange: 36460r, Delegate: 0x200042e0
I: 627375 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 627383 [IN]CASE Server disabling CASE session setups
I: 627388 [EM]<<< [E:36460r M:171505224 (Ack:194927176)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 627401 [IN](U) Sending msg 171505224 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43888'
D: 627411 [EM]Flushed pending ack for MessageCounter:194927176 on exchange 36460r
I: 627418 [SC]Received Sigma1 msg
D: 627422 [SC]Found MRP parameters in the message
D: 627426 [SC]Peer assigned session key ID 52854
I: 627435 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 627657 [SC]Including MRP parameters
I: 627661 [EM]<<< [E:36460r M:171505225 (Ack:194927176)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 627674 [IN](U) Sending msg 171505225 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43888'
I: 627685 [SC]Sent Sigma2 msg
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 627697 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa227
D: Current event: 8
D: 628041 [EM]Retransmitting MessageCounter:171505225 on exchange 36460r Send Cnt 1
I: 628049 [IN](U) Sending msg 171505225 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43888'
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 628196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa228
D: Current event: 8
D: 628432 [EM]Retransmitting MessageCounter:171505225 on exchange 36460r Send Cnt 2
I: 628440 [IN](U) Sending msg 171505225 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43888'
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 628696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa229
D: Current event: 8
D: 628975 [EM]Retransmitting MessageCounter:171505225 on exchange 36460r Send Cnt 3
I: 628983 [IN](U) Sending msg 171505225 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43888'
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 629196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa22a
D: Current event: 8
I: 629392 [EM]>>> [E:36460r M:194927177 (Ack:171505225)] (U) Msg RX from 0:DEF17CDE5AF763F3 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 629406 [EM]Found matching exchange: 36460r, Delegate: 0x200042fc
D: 629412 [EM]Rxd Ack; Removing MessageCounter:171505225 from Retrans Table on exchange 36460r
I: 629421 [EM]<<< [E:36460r M:171505226 (Ack:194927177)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 629434 [IN](U) Sending msg 171505226 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43888'
D: 629445 [EM]Flushed pending ack for MessageCounter:194927177 on exchange 36460r
I: 629452 [SC]Received Sigma3 msg
E: 629460 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 629696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa22b
D: Current event: 8
D: 629749 [SC]Sending status report. Protocol code 0, exchange 36460
I: 629756 [EM]<<< [E:36460r M:171505227 (Ack:194927177)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 629769 [IN](U) Sending msg 171505227 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43888'
I: 629780 [SC]SecureSession[0x20003e58]: Moving from state 'kEstablishing' --> 'kActive'
D: 629788 [IN]SecureSession[0x20003e58]: Activated - Type:2 LSID:56918
D: 629795 [IN]New secure session activated for device <000000000001B669, 1>, LSID:56918 PSID:52854!
I: 629804 [IN]CASE Session established to peer: <000000000001B669, 1>
0SE Server enabling CASE session setups
D: 629815 [IN]SecureSession[0x20003f10]: Allocated Type:2 LSID:56919
D: 629823 [SC]Allocated SecureSession (0x20003f10) - waiting for Sigma1 msg
I: 629832 [EM]>>> [E:36461r M:118052773] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0001:02 (IM:ReadRequest)
D: 629843 [EM]Handling via exchange: 36461r, Delegate: 0x2000d504
D: 629849 [IM]Received Read request
D: 629852 [DMG]IM RH moving to [GeneratingReports]
D: 629857 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 629866 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 629871 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 629880 [DMG]<RE> Sending report (payload has 38 bytes)...
I: 629886 [EM]<<< [E:36461r M:112064972 (Ack:118052773)] (S) Msg TX to 1:000000000001B669 [0EBD] --- Type 0001:05 (IM:ReportData)
I: 629898 [IN](S) Sending msg 112064972 on secure session with LSID: 56918
D: 629905 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 629910 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 629918 [DMG]IM RH moving to [AwaitingDestruction]
D: 629923 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 629930 [EM]>>> [E:36460r M:194927178 (Ack:171505227)] (U) Msg RX from 0:DEF17CDE5AF763F3 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 629942 [EM]Found matching exchange: 36460r, Delegate: (nil)
D: 629948 [EM]Rxd Ack; Removing MessageCounter:171505227 from Retrans Table on exchange 36460r
I: 629959 [EM]>>> [E:36461r M:118052774 (Ack:112064972)] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 629973 [EM]Found matching exchange: 36461r, Delegate12064972 from Retrans Table on exchange 36461r
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 630196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa22c
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 630696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa22d
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 631196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa22e
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 631696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa22f
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 632196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa230
D: Current event: 8
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[2D~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: Event put result: 0
D: Event in queue:8t in queue: type: 8
DDMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa232
D: Current event: 8
 put result: 0
D: Event in queue: date version t update vera234
D: Current event:I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 634696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa235
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 635196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa236
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 635696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa237
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 636196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa238
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 636696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa239
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 637196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa23a
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 637696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa23b
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 638196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa23c
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 638696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa23d
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 639197 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa23e
D: Current event: 8
I: 639207 [EM]>>> [E:48953r M:98860027] (U) Msg RX from 0:07C22687C52EECCC [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 639218 [EM]Handling via exchange: 48953r, Delegate: 0x200042e0
I: 639224 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 639231 [IN]CASE Server disabling CASE session setups
I: 639236 [EM]<<< [E:48953r M:171505228 (Ack:98860027)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 639249 [IN](U) Sending msg 171505228 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:33677'
D: 639260 [EM]Flushed pending ack for MessageCounter:98860027 on exchange 48953r
I: 639267 [SC]Received Sigma1 msg
D: 639270 [SC]Found MRP parameters in the message
D: 639275 [SC]Peer assigned session key ID 18077
I: 639283 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 639505 [SC]Including MRP parameters
I: 639510 [EM]<<< [E:48953r M:171505229 (Ack:98860027)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 639522 [IN](U) Sending msg 171505229 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:33677'
I: 639533 [SC]Sent Sigma2 msg
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 639697 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa23f
D: Current event: 8
I: 639724 [EM]>>> [E:48953r M:98860028 (Ack:171505229)] (U) Msg RX from 0:07C22687C52EECCC [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 639737 [EM]Found matching exchange: 48953r, Delegate: 0x200042fc
D: 639743 [EM]Rxd Ack; Removing MessageCounter:171505229 from Retrans Table on exchange 48953r
I: 639751 [EM]<<< [E:48953r M:171505230 (Ack:98860028)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 639764 [IN](U) Sending msg 171505230 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:33677'
D: 639774 [EM]Flushed pending ack for MessageCounter:98860028 on exchange 48953r
I: 639782 [SC]Received Sigma3 msg
E: 639789 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 640067 [SC]Sending status report. Protocol code 0, exchange 48953
I: 640074 [EM]<<< [E:48953r M:171505231 (Ack:98860028)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 640086 [IN](U) Sending msg 171505231 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:33677'
I: 640098 [SC]SecureSession[0x20003f10]: Moving from state 'kEstablishing' --> 'kActive'
D: 640106 [IN]SecureSession[0x20003f10]: Activated - Type:2 LSID:56919
D: 640113 [IN]New secure session activated for device <000000000001B669, 1>, LSID:56919 PSID:18077!
I: 640122 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 640128 [IN]CASE Server enabling CASE session setups
D: 640133 [IN]SecureSession[0x20003fc8]: Allocated Type:2 LSID:56920
D: 640139 [SC]Allocated SecureSession (0x20003fc8) - waiting for Sigma1 msg
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 640196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa240
D: Current event: 8
I: 640207 [EM]>>> [E:48954r M:114641056] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0001:02 (IM:ReadRequest)
D: 640219 [EM]Handling via excha48954r, Delegate: 0x2000d504
D: 640225 [IM]Received Read request
D: 640229 [DMG]IM RH moving to [GeneratingReports]
D: 640233 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 640242 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 640247 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 640256 [DMG]<RE> Sending report (payload has 38 bytes)...
I: 640263 [EM]<<< [E:48954r M:177937470 (Ack:114641056)] (S) Msg TX to 1:000000000001B669 [0EBD] --- Type 0001:05 (IM:ReportData)
I: 640274 [IN](S) Sending msg 177937470 on secure session with LSID: 56919
D: 640282 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 640286 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 640294 [DMG]IM RH moving to [AwaitingDestruction]
D: 640299 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 640305 [EM]>>> [E:48953r M:98860029 (Ack:171505231)] (U) Msg RX from 0:07C22687C52EECCC [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 640318 [EM]Found matching exchange: 48953r, Delegate: (nil)
D: 640324 [EM]Rxd Ack; Removing MessageCounter:171505231 from Retrans Table on exchange 48953r
I: 640357 [EM]>>> [E:48954r M:114641057 (Ack:177937470)] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 640370 [EM]Found matching exchange: 48954r, Delegate: (nil)
D: 640376 [EM]Rxd Ack; Removing MessageCounter:177937470 from Retrans Table on exchange 48954r
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 640696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa241
D: Current event: 8
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~: Event put result: 0
D: Event in queue: 8
I: Event type: 8
]Endpoint 1, Cluster 0x0000_0402 update version to 819fa242
D: Current event: 8
I: Evet: 0
D: Event in queue: 8
I: EveD: 641696t 1, Cluster 0x0000_04807 [EM]>>>30 (SecureChannel:CASE_Sigma1)
D: 641819 [EM]Ha 0x200042e0
recei handshaI: 641837 [E:21398r M:17150232 (Ack:161002278)] (U) Msg TX to00000000 [00071505232 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:53902'
D: 641860 [EM]Flushed pending ack for MessageCoun1002278 on exchange 21398r
I: 641868 [SC]Received Sigma1 msg
D: 641871 [
[SC]CASE matched destination ID: fab, [SC]Including MRP parameters
I: 642113 [EM]<<< [E:21398r M:171505233 (Ack:161002278)] (U) Msg TX to 0:00000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 642126 [IN](U) Sending msg 171505233 to IP address 'UDP:[fd89:2db1:2'
I: 642137C]Sent Sigma2 msg
I: Eveent in queueuster 0x0000_0402 update versiot event: 8D: 642472nsmitting Meson exchange Cnt 1
I: 64248[IN](U) Sending msg 171505233 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:53902'
ent in queue: 8
I: Event type: 8
D: 642696 [DMG]EndpoD: 642889 [EM]Retransmitting MessageCounter:171505233 on exchange 21398r Send Cnt 2
I: 642896 [IN](U) Sending msg 171505233 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:53902'
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 643196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa246
D: Current event: 8
D: 643538 [EM]Retransmitting MessageCounter:171505233 on exchange 21398r Send Cnt 3
I: 643546 [IN](U) Sending msg 171505233 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:53902'
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 643696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa247
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 644196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa248
D: Current event: 8
I: 644260 [EM]>>> [E:21398r M:161002279 (Ack:171505233)] (U) Msg RX from 0:71A7065B34F50E23 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 644273 [EM]Found matching exchange: 21398r, Delegate: 0x200042fc
D: 644279 [EM]Rxd Ack; Removing MessageCounter:171505233 from Retrans Table on exchange 21398r
I: 644288 [EM]<<< [E:21398r M:171505234 (Ack:161002279)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 644300 [IN](U) Sending msg 171505234 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:53902'
D: 644311 [EM]Flushed pending ack for MessageCounter:161002279 on exchange 21398r
I: 644318 [SC]Received Sigma3 msg
E: 644326 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 644606 [SC]Sending status report. Protocol code 0, exchange 21398
I: 644612 [EM]<<< [E:21398r M:171505235 (Ack:161002279)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 644625 [IN](U) Sending msg 171505235 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:53902'
I: 644637 [SC]SecureSession[0x20003fc8]: Moving from state 'kEstablishing' --> 'kActive'
D: 644645 [IN]SecureSession[0x20003fc8]: Activated - Type:2 LSID:56920
D: 644652 [IN]New secure session activated for device <000000000001B669, 1>, LSID:56920 PSID:28438!
I: 644660 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 644667 [IN]CASE Server enabling CASE session setups
D: 644672 [IN]SecureSession[0x20004080]: Allocated Type:2 LSID:56921
D: 644678 [SC]Allocated SecureSession (0x20004080) - waiting for Sigma1 msg
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 644696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa249
D: Current event: 8
I: 644724 [EM]>>> [E:21399r M:61419847] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0001:02 (IM:ReadRequest)
D: 644735 [EM]Handling via exchange: 21399r, Delegate: 0x2000d504
D: 644741 [IM]Received Read request
D: 644745 [DMG]IM RH moving to [GeneratingReports]
D: 644750 [DMG]Building Reports for ReadHandlxpanded=0)
D: 644773 [DMG]<RE> Sending report (payload has 38 bytes)...
I: 644779 [EM]<<< [E:21399r M:254479144 (Ack:61419847)] (S) Msg TX to 1:000000000001B669 [0EBD] --- Type 0001:05 (IM:ReportData)
I: 644790 [IN](S) Sending msg 254479144 on secure session with LSID: 56920
D: 644798 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 644803 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 644811 [DMG]IM RH moving to [AwaitingDestruction]
D: 644816 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 644822 [EM]>>> [E:21398r M:161002280 (Ack:171505235)] (U) Msg RX from 0:71A7065B34F50E23 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 644835 [EM]Found matching exchange: 21398r, Delegate: (nil)
D: 644841 [EM]Rxd Ack; Removing MessageCounter:171505235 from Retrans Table on exchange 21398r
I: 644863 [EM]>>> [E:21399r M:61419848 (Ack:254479144)] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 644876 [EM]Found matching exchange: 21399r, Delegate: (nil)
D: 644882 [EM]Rxd Ack; Removing MessageCounter:254479144 from Retrans Table on exchange 21399r
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 645196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa24a
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 645696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa24b
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 646196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa24c
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 646696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa24d
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 647196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa24e
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 647696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa24f
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 648196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa250
D: Current event: 8
I: 648233 [EM]>>> [E:63983r M:37139537] (U) Msg RX from 0:0CD9B77345A39702 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 648244 [EM]Handling via exchange: 63983r, Delegate: 0x200042e0
I: 648250 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0r disabling CASE session setups
I: 648263 [EM]<<< [E:63983r M:171505236 (Ack:37139537)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 648275 [IN](U) Sending msg 171505236 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43404'
D: 648286 [EM]Flushed pending ack for MessageCounter:37139537 on exchange 63983r
I: 648293 [SC]Received Sigma1 msg
D: 648296 [SC]Found MRP parameters in the message
D: 648301 [SC]Peer assigned session key ID 57418
I: 648309 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 648530 [SC]Including MRP parameters
I: 648535 [EM]<<< [E:63983r M:171505237 (Ack:37139537)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 648547 [IN](U) Sending msg 171505237 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43404'
I: 648558 [SC]Sent Sigma2 msg
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 648697 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa251
D: Current event: 8
I: 648706 [EM]>>> [E:63983r M:37139538 (Ack:171505237)] (U) Msg RX from 0:0CD9B77345A39702 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 648719 [EM]Found matching exchange: 63983r, Delegate: 0x200042fc
D: 648725 [EM]Rxd Ack; Removing MessageCounter:171505237 from Retrans Table on exchange 63983r
I: 648734 [EM]<<< [E:63983r M:171505238 (Ack:37139538)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 648746 [IN](U) Sending msg 171505238 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43404'
D: 648757 [EM]Flushed pending ack for MessageCounter:37139538 on exchange 63983r
I: 648764 [SC]Received Sigma3 msg
E: 648771 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 649048 [SC]Sending status report. Protocol code 0, exchange 63983
I: 649055 [EM]<<< [E:63983r M:171505239 (Ack:37139538)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 649067 [IN](U) Sending msg 171505239 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43404'
I: 649079 [SC]SecureSession[0x20004080]: Moving from state 'kEstablishing' --> 'kActive'
D: 649088 [IN]SecureSession[0x20004080]: Activated - Type:2 LSID:56921
D: 649094 [IN]New secure session activated for device <000000000001B669, 1>, LSID:56921 PSID:57418!
I: 649103 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 649109 [IN]CASE Server enabling CASE session setups
D: 649114 [IN]SecureSession[0x20004138]: Allocated Type:2 LSID:56922
D: 649120 [SC]Allocated SecureSession (0x20004138) - waiting for Sigma1 msg
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 649197 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa252
D: Current event: 8
I: 649208 [EM]>>> [E:63984r M:62937537] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0001:02 (IM:ReadRequest)
D: 649218 [EM]Handling via exchange: 63984r, Delegate: 0x2000d504
D: 649224 [IM]Received Read request
D: 649228 [DMG]IM RH moving to [GeneratingReports]
D: 649232 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 649241 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 649246 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 649255 [DMG]<RE> Sending report (payload has 38 bytes)...
I: 649262 [EM]<<< [E:63984r M:116368882 (Ack:62937537)] (S) Msg TX to 1:000000000001B669 [0EBD] --- Type 0001:05 (IM:ReportData)
I: 649273 [IN](S) Sending msg 116368882 on secure session with LSID: 56921
D: 649281 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 649285 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 649293 [DMG]IM RH moving to [AwaitingDestruction]
D: 649298 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 649304 [EM]>>> [E:63983r M:37139539 (Ack:171505239)] (U) Msg RX from 0:0CD9B77345A39702 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 649317 [EM]Found matching exchange: 63983r, Delegate: (nil)
D: 649323 [EM]Rxd Ack; Removing MessageCounter:171505239 from Retrans Table on exchange 63983r
I: 649340 [EM]>>> [E:63984r M:62937538 (Ack:116368882)] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 649352 [EM]Found matching exchange: 63984r, Delegate: (nil)
D: 649358 [EM]Rxd Ack; Removing MessageCounter:116368882 from Retrans Table on exchange 63984r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
I: Eult: 0
D: Event in queue: 8
I: Event type: 8
D: 649696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa253
D: Current event: 8
I: Event put reEvent in queter 0x0000_0402 update version to 819fa254
D: Current event: 8
I: Evult: 0
D: Event in queue: 8
I: Event type: 8
D: 650696 [DMG]Endpoint 1, Clusvent put res
D: 651196 [DMG]Endpoint 1, Clus0402 update ent: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 651696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa257
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 652196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa258
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 652696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa259
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 653196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa25a
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 653696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa25b
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 654196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa25c
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 654696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa25d
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 655196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa25e
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 655696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa25f
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 656196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa260
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 656696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa261
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 657196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa262
D: Current event: 8
I: Event put result: 0
D Event type:dpoint 1, Custer 0x0000D: Current e~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~[~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~I: Event put rqueue: 8
I: Event type: 8
D: 658 Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 658point 1, Cluster 0x0000_0402 update version to 819fa265
D: Current eEvent put result: 0
Dqueue: 8
I:: 8
D: 659196 [: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 659696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa267
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 660196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa268
D: Current event: 8
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 660696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa269
D: Current event: 8
I: 661101 [EM]>>> [E:41636r M:177685478] (U) Msg RX from 0:968ABD7FFF43BB6D [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 661113 [EM]Handling via exchange: 41636r, Delegate: 0x200042e0
I: 661119 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 661126 [IN]CASE Server disabling CASE session setups
I: 661131 [EM]<<< [E:41636r M:171505240 (Ack:177685478)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 661144 [IN](U) Sending msg 171505240 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:58614'
D: 661154 [EM]Flushed pending ack for MessageCounter:177685478 on exchange 41636r
I: 661162 [SC]Received Sigma1 msg
D: 661165 [SC]Found MRP parameters in the message
D: 661170 [SC]Peer assigned session key ID 50964
I: 661178 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 661196 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa26a
D: Current event: 8
D: 661413 [SC]Including MRP parameters
I: 661417 [EM]<<< [E:41636r M:171505241 (Ack:177685478)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 661430 [IN](U) Sending msg 171505241 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:58614'
I: 661441 [SC]Sent Sigma2 msg
I: 661573 [EM]>>> [E:41636r M:177685479 (Ack:171505241)] (U) Msg RX from 0:968ABD7FFF43BB6D [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 661586 [EM]Found matching exchange: 41636r, Delegate: 0x200042fc
D: 661592 [EM]Rxd Ack; Removing MessageCounter:171505241 from Retrans Table on exchange 41636r
I: 661601 [EM]<<< [E:41636r M:171505242 (Ack:177685479)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 661614 [IN](U) Sending msg 171505242 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:58614'
D: 661624 [EM]Flushed pending ack for MessageCounter:177685479 on exchange 41636r
I: 661631 [SC]Received Sigma3 msg
E: 661639 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
I: Event put result: 0
D: Event in queue: 8
I: Event type: 8
D: 661696 [DMG]Endpoint 1, Cluster 0x0000_0402 update version to 819fa26b
D: Current event: 8
D: 661933 [SC]Sending status report. Protocol code 0, exchange 41636
I: 661939 [EM]<<< [E:41636r M:171505243 (Ack:177685479)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 661952 [IN](U) Sending msg 171505243 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:58614'
I: 661963 [SC]SecureSession[0x20004138]: Moving from state 'kEstablishing' --> 'kActive'
D: 661972 [IN]SecureSession[0x20004138]: Activated - Type:2 LSID:56922
D: 661978 [IN]New secure session activated for device <000000000001B669, 1>, LSID:56922 PSID:50964!
I: 661988 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 661994 [IN]CASE Server ena [SC]Allocated SecureSession (0x200041f0) - waiting for Sigma1 msg
I: 662047 [EM]>>> [E:41637r M:35805232] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0001:08 (IM:InvokeCommandRequest)
D: 662059 [EM]Handling via exchange: 41637r, Delegate: 0x2000d504
D: 662066 [DMG]Received command for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0000
I: 662073 [ZCL]On/Off set value: 1 0
I: 662077 [ZCL]Toggle on/off from 1 to 0
D: 662081 [DMG]Endpoint 1, Cluster 0x0000_0006 update version to 3a33f21f
I: Event type: 7
D: Current event: 7
I: Event put result: 0
D: Event in queue: 7
D: 662094 [DMG]Command handler moving to [ Preparing]
D: 662099 [DMG]Command handler moving to [AddingComm]
D: 662104 [DMG]Command handler moving to [AddedComma]
D: 662109 [DMG]Decreasing reference count for CommandHandler, remaining 0
I: 662116 [EM]<<< [E:41637r M:85085546 (Ack:35805232)] (S) Msg TX to 1:000000000001B669 [0EBD] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 662129 [IN](S) Sending msg 85085546 on secure session with LSID: 56922
D: 662136 [DMG]Command handler moving to [CommandSen]
D: 662141 [DMG]Command handler moving to [AwaitingDe]
I: 662147 [EM]>>> [E:41636r M:177685480 (Ack:171505243)] (U) Msg RX from 0:968ABD7FFF43BB6D [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 662160 [EM]Found matching exchange: 41636r, Delegate: (nil)
D: 662167 [EM]Rxd Ack; Removing MessageCounter:171505243 from Retrans Table on exchange 41636r
I: 662176 [EM]>>> [E:41637r M:35805233 (Ack:85085546)] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 662189 [EM]Found matching exchange: 41637r, Delegate: (nil)
D: 662195 [EM]Rxd Ack; RemageCounter:85 Table on exchange 41637r
I: 664180 [EM]>>> [E:25391r M:169302257] (U) Msg RX from 0:1AED29C75F2AF945 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
D: 664191 [EM]Handling via exchange: 25391r, Delegate: 0x200042e0
I: 664197 [IN]CASE Server received Sigma1 message. Starting handshake. EC 0x20004ff0
I: 664204 [IN]CASE Server disabling CASE session setups
I: 664209 [EM]<<< [E:25391r M:171505244 (Ack:169302257)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 664222 [IN](U) Sending msg 171505244 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43295'
D: 664233 [EM]Flushed pending ack for MessageCounter:169302257 on exchange 25391r
I: 664240 [SC]Received Sigma1 msg
D: 664244 [SC]Found MRP parameters in th43834
I: 664256 [SC]CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000001
D: 664478 [SC]Including MRP parameters
I: 664482 [EM]<<< [E:25391r M:171505245 (Ack:169302257)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
I: 664495 [IN](U) Sending msg 171505245 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43295'
I: 664506 [SC]Sent I: 664638 [EM]>>> [E:25391r M:169302258 (Ack:171505245)] (U) Msg RX from 0:1AED29C75F2AF945 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
D: 664651 [EM]Found matching exchange: 25391r, Delegate: 0x200042fc
D: 664657 [EM]Rxd Ack; Removing MessageCounter:171505245 from Retrans Table on exchange 25391r
I: 664666 [EM]<<< [E:25391r M:171505246 (Ack:169302258)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 664678 [IN](U) Sending msg 171505246 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43295'
D: 664689 [EM]Flushed pending ack for MessageCounter:169302258 on exchange 25391r
I: 664696 [SC]Received Sigma3 msg
E: 664704 [SC]The device does not support GetClock_RealTimeMS() API: 3.  Falling back to Last Known Good UTC Time
D: 664980 [SC]Sending status report. Protocol code 0, exchange 25391
I: 664986 [EM]<<< [E:25391r M:171505247 (Ack:169302258)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
I: 664999 [IN](U) Sending msg 171505247 to IP address 'UDP:[fd89:2db1:a6ad:f291:dde4:c847:f114:4f2a]:43295'
I: 665011 [SC]SecureSession[0x200041f0]: Moving from state 'kEstablishing' --> 'kActive'
D: 665019 [IN]SecureSession[0x200041f0]: Activated - Type:2 LSID:56923
D: 665026 [IN]New secure session activated for device <000000000001B669, 1>, LSID:56923 PSID:43834!
I: 665036 [IN]CASE Session established to peer: <000000000001B669, 1>
I: 665044 [IN]CASE Server enabling CASE session setups
I: 665049 [SC]Evicting a slot for session with LSID: 56924, type: 2
I: 665056 [SC]Sorted sessions for eviction...
D: 665060 [SC]Sorted Eviction Candidates (ranked from best candidate to worst):
D: 665067 [SC]	0: [0x20003728] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 175922
D: 665080 [SC]	1: [0x200037e0] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 193777
D: 665093 [SC]	2: [0x20003670] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 305728
D: 665106 [SC]	3: [0x20003898] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 312074
D: 665119 [SC]	4: [0x20003950] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 318168
D: 665132 [SC]	5: [0x20003a08] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 362077
D: 665145 [SC]	6: [0x20003ac0] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 368316
D: 665158 [SC]	7: [0x20003b78] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 376733
D: 665171 [SC]	8: [0x20003c30] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 380594
D: 665184 [SC]	9: [0x20003ce8] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 384898
D: 665197 [SC]	10: [0x20003da0] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 572551
D: 665210 [SC]	11: [0x20003e58] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 629959
D: 665223 [SC]	12: [0x20003f10] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 640357
D: 665236 [SC]	13: [0x20003fc8] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 644863
D: 665249 [SC]	14: [0x20004080] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 649339
D: 665262 [SC]	15: [0x20004138] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 662176
D: 665275 [SC]	16: [0x200041f0] -- Peer: [1:000000000001B669] State: 'kActive', NumMatchingOnFabric: 16 NumMatchingOnPeer: 16 ActivityTime: 665011
I: 665288 [SC]Candidate Session[0x20003728] - Attempting to evict...
D: 665294 [IN]SecureSession[0x20003728]: MarkForEviction Type:2 LSID:56907
I: 665301 [SC]SecureSession[0x20003728]: Moving from state 'kActive' --> 'kPendingEviction'
D: 665309 [IN]SecureSession[0x20003728]: Released - Type:2 LSID:56907
I: 665315 [SC]Successfully evicted a session!
D: 665320 [IN]SecureSession[0x20003728]: Allocated Type:2 LSID:56924
D: 665326 [SC]Allocated SecureSession (0x20003728) - waiting for Sigma1 msg
I: 665333 [EM]>>> [E:25392r M:252961790] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0001:02 (IM:ReadRequest)
D: 665344 [EM]Handling via exchange: 25392r, Delegate: 0x2000d504
D: 665349 [IM]Received Read request
D: 665353 [DMG]IM RH moving to [GeneratingReports]
D: 665358 [DMG]Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
D: 665367 [DMG]<RE:Run> Cluster 402, Attribute 0 is dirty
D: 665372 [DMG]Reading attribute: Cluster=0x0000_0402 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
D: 665381 [DMG]<RE> Sending report (payload has 38 bytes)...
I: 665389 [EM]<<< [E:25392r M:248697776 (Ack:252961790)] (S) Msg TX to 1:000000000001B669 [0EBD] --- Type 0001:05 (IM:ReportData)
I: 665400 [IN](S) Sending msg 248697776 on secure session with LSID: 56923
D: 665408 [DMG]<RE> OnReportConfirm: NumReports = 0
D: 665413 [DMG]<RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
D: 665421 [DMG]IM RH moving to [AwaitingDestruction]
D: 665425 [DMG]All ReadHandler-s are clean, clear GlobalDirtySet
I: 665431 [EM]>>> [E:25391r M:169302259 (Ack:171505247)] (U) Msg RX from 0:1AED29C75F2AF945 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 665446 [EM]Found matching exchange: 25391r, Delegate: (nil)
D: 665451 [EM]Rxd Ack; Removing MessageCounter:171505247 from Retrans Table on exchange 25391r
D: 665461 [IN]Received a duplicate message with MessageCounter:252961790 on exchange 25392r
I: 665469 [EM]>>> [E:25392r M:252961790] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0001:02 (IM:ReadRequest)
D: 665479 [EM]Found matching exchange: 25392r, Delegate: (nil)
D: 665485 [EM]Forcing tx of solitary ack for duplicate MessageCounter:252961790 on exchange 25392r
I: 665494 [EM]<<< [E:25392r M:248697777 (Ack:252961790)] (S) Msg TX to 1:000000000001B669 [0EBD] --- Type 0000:10 (SecureChannel:StandaloneAck)
I: 665507 [IN](S) Sending msg 248697777 on secure session with LSID: 56923
I: 665515 [EM]>>> [E:25392r M:252961791 (Ack:248697776)] (S) Msg RX from 1:000000000001B669 [0EBD] --- Type 0000:10 (SecureChannel:StandaloneAck)
D: 665529 [EM]Found matching exchange: 25392r, Delegate: (nil)
D: 665534 [EM]Rxd Ack; Removing MessageCounter:248697776 from Retrans Table on exchange 25392r
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

    Since this variable was provided into the function for the tutorial given, will it be updated? Let me know if there is anything I can do to help!

  • 0 in reply to kendrik-dev

    Hi,

    I'm glad you managed to get it to work! 

    kendrik-dev said:
    Since this variable was provided into the function for the tutorial given, will it be updated? Let me know if there is anything I can do to help!

    Yes, this will be updated. We've brought this up to the Matter developers and tech writers and the tutorial will be updated to acommodate the change in MatterPostAttributeChangeCallback

    Kind regards,
    Andreas

Related
Terms of service