Endpoint 1, Cluster 0x0000_0006 update version to d0856da6, log message shown when setting a value in on/off attribute.

[alvin7]

Hi,

As the title suggests, whenever I try to set the on/off attribute of the on/off cluster, the above log message is shown.
I am using vs code with nrf connect sdk v2.1.1 and working off the template sample. 

I added 8 endpoints to my project with 8 gpio interrupts triggering the setting of the on/off attribute in their respective endpoints. 
But whenever I trigger the gpio interrupt to set the on/off attribute, that particular log message is shown. Its the same for all the other endpoints as well.

I don't understand why this is happening. What does it mean?

I will attach the entire log below for your reference. Thank you in advance.

Fullscreen 2605.New Text Document.txt Download

uart:~$ I: nRF5 802154 radio initialized
I: 4 Sectors of 4096 bytes
I: alloc wra: 0, f58
I: data wra: 0, 90
*** Booting Zephyr OS build v3.1.99-ncs1  ***
I: Init CHIP stack
I: 169 [DL]BLE address: FC:31:F1:20:44:D8
I: 193 [DL]OpenThread started: OK
I: 196 [DL]Setting OpenThread device type to MINIMAL END DEVICE
Init Touch Config
I: 204 [SVR]Server initializing...
D: 207 [FP]Initializing FabricTable from persistent storage
I: 212 [TS]Last Known Good Time: 2023-01-04T17:56:09
I: 217 [DMG]AccessControl: initializing
I: 221 [DMG]Examples::AccessControlDelegate::Init
I: 225 [DMG]AccessControl: setting
I: 228 [DMG]DefaultAclStorage: initializing
I: 232 [DMG]DefaultAclStorage: 0 entries loaded
D: 237 [IN]UDP::Init bind&listen port=5540
E: 240 [IN]SO_REUSEPORT failed: 109
D: 244 [IN]UDP::Init bound to port=5540
D: 247 [IN]BLEBase::Init - setting/overriding transport
D: 252 [IN]TransportMgr initialized
D: 257 [DL]Using Thread extended MAC for hostname.
I: 262 [ZCL]Using ZAP configuration...
D: 267 [DMG]Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0
I: 277 [DMG]AccessControlCluster: initializing
D: 281 [DMG]Endpoint 0, Cluster 0x0000_0030 update version to bcce792
D: 287 [DL]Boot reason: 1
D: 290 [ZCL]GeneralDiagnostics: OnDeviceReboot
D: 294 [DMG]Endpoint 0, Cluster 0x0000_0033 update version to ea33be60
D: 300 [EVL]LogEvent event number: 0x0000000000010000 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x000000000000012C
I: 314 [ZCL]Initiating Admin Commissioning cluster.
D: 319 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to 880780d2
D: 325 [DMG]Endpoint 1, Cluster 0x0000_0004 update version to 880780d3
D: 331 [DMG]Endpoint 1, Cluster 0x0000_0005 update version to f7d42d1e
D: 338 [DMG]Endpoint 2, Cluster 0x0000_0004 update version to 6d8daf35
D: 344 [DMG]Endpoint 2, Cluster 0x0000_0004 update version to 6d8daf36
D: 350 [DMG]Endpoint 2, Cluster 0x0000_0005 update version to 2e1ded34
D: 357 [DMG]Endpoint 3, Cluster 0x0000_0004 update version to fb183a59
D: 363 [DMG]Endpoint 3, Cluster 0x0000_0004 update version to fb183a5a
D: 369 [DMG]Endpoint 3, Cluster 0x0000_0005 update version to bdb11ff5
D: 376 [DMG]Endpoint 4, Cluster 0x0000_0004 update version to e9f14448
D: 382 [DMG]Endpoint 4, Cluster 0x0000_0004 update version to e9f14449
D: 389 [DMG]Endpoint 4, Cluster 0x0000_0005 update version to f8a3c129
D: 395 [DMG]Endpoint 5, Cluster 0x0000_0004 update version to 150a81f0
D: 401 [DMG]Endpoint 5, Cluster 0x0000_0004 update version to 150a81f1
D: 408 [DMG]Endpoint 5, Cluster 0x0000_0005 update version to e4fcc314
D: 414 [DMG]Endpoint 6, Cluster 0x0000_0004 update version to 7efc24ba
D: 420 [DMG]Endpoint 6, Cluster 0x0000_0004 update version to 7efc24bb
D: 427 [DMG]Endpoint 6, Cluster 0x0000_0005 update version to 44fc8174
D: 433 [DMG]Endpoint 7, Cluster 0x0000_0004 update version to f478cced
D: 440 [DMG]Endpoint 7, Cluster 0x0000_0004 update version to f478ccee
D: 446 [DMG]Endpoint 7, Cluster 0x0000_0005 update version to a33241e1
D: 452 [DMG]Endpoint 8, Cluster 0x0000_0004 update version to 5e607041
D: 459 [DMG]Endpoint 8, Cluster 0x0000_0004 update version to 5e607042
D: 465 [DMG]Endpoint 8, Cluster 0x0000_0005 update version to e8c6e6c0
D: 473 [IN]SecureSession[0x20004550]: Allocated Type:1 LSID:64631
D: 479 [SC]Assigned local session key ID 64631
D: 483 [SC]Waiting for PBKDF param request
D: 486 [DL]CHIPoBLE advertising set to on
I: 490 [DIS]Updating services using commissioning mode 1
D: 495 [DL]Using Thread extended MAC for hostname.
D: 500 [DL]Using Thread extended MAC for hostname.
I: 505 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1
E: 514 [DIS]Failed to advertise commissionable node: 3
E: 519 [DIS]Failed to finalize service update: 1c
I: 523 [DIS]Updating services using commissioning mode 1
D: 528 [DL]Using Thread extended MAC for hostname.
D: 533 [DL]Using Thread extended MAC for hostname.
I: 538 [DIS]Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1
E: 547 [DIS]Failed to advertise commissionable node: 3
E: 552 [DIS]Failed to finalize service update: 1c
I: 556 [DIS]Delaying proxy of operational discovery: missing delegate
I: 563 [IN]CASE Server enabling CASE session setups
D: 568 [IN]SecureSession[0x20004608]: Allocated Type:2 LSID:64632
D: 573 [SC]Allocated SecureSession (0x20004608) - waiting for Sigma1 msg
I: 580 [SVR]Joining Multicast groups
D: 583 [ZCL]Emitting StartUp event
D: 586 [EVL]LogEvent event number: 0x0000000000010001 priority: 2, endpoint id:  0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x000000000000024A
I: 600 [SVR]Server Listening...
I: 603 [DL]Device Configuration:
I: 606 [DL]  Serial Number: 11223344556677889900
I: 610 [DL]  Vendor Id: 65521 (0xFFF1)
I: 614 [DL]  Product Id: 32768 (0x8000)
I: 618 [DL]  Hardware Version: 0
I: 621 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
I: 626 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
I: 633 [DL]  Manufacturing Date: (not set)
I: 637 [DL]  Device Type: 65535 (0xFFFF)
I: 641 [SVR]SetupQRCode: [MT:Y.K9042C00KA0648G00]
I: 645 [SVR]Copy/paste the below URL in a browser to see the QR Code:
I: 651 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3AY.K9042C00KA0648G00
I: 660 [SVR]Manual pairing code: [34970112332]
I: 665 [DL]CHIP task running
I: 672 [DL]CHIPoBLE advertising started
Entered isr
enteer UpdateClusterState
D: 3457 [DMG]Endpoint 1, Cluster 0x0000_0006 update version to 6a9bbec9
ext UpdateClusterState
Exited isr

[Amanda Hsieh]

Hi, 

So these logs indicate the version of an attribute which is simply metadata used to see if one attribute has already been changed. Each DataVersion is incremented by each change, starting with a randomly generated number. These logs will not be present in the next NCS release because of the latest LOG infrastructure optimizations but these will be configurable, i.e. a user will be able to select/deselect logs with a particular log level for a particular Matter module. Here is the upstream PR, already cherry-picked to our fork: https://github.com/project-chip/connectedhomeip/pull/24189

Regards,
Amanda H.

[alvin7]

Ok. But when I try to update the cluster state, it does not invoke the "MatterPostAttributeChangeCallback". When i change the attribute, the return value is success but it doesnt enter the matter callback. It only shows that particular log mentioned above.