Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[TE9] Get UNSUPPORTED_ATTRIBUTE of read command on DL-3.1 #18492

Closed
cabin15 opened this issue May 17, 2022 · 6 comments · Fixed by #19063
Closed

[TE9] Get UNSUPPORTED_ATTRIBUTE of read command on DL-3.1 #18492

cabin15 opened this issue May 17, 2022 · 6 comments · Fixed by #19063
Assignees
Labels
app-clusters Application cluster work spec Mismatch between spec and implementation V1.0

Comments

@cabin15
Copy link
Contributor

cabin15 commented May 17, 2022

Problem

Controller: My DUT
Controlee: all-clusters-app of test Harness image on rpi4

When reading attribute of doorlock cluster from all-clusters-app, my DUT got UNSUPPORTED_ATTRIBUTE return.

Belows are the attribute that failed to read.

  • number-of-logs-records-supported
  • enable-logging
  • ledsettings
  • local-programming-features
  • send-pinover-the-air
  • expiring-user-timeout
  • alarm-mask
  • keypad-operation-event-mask
  • remote-operation-event-mask
  • manual-operation-event-mask
  • rfidoperation-event-mask
  • keypad-programming-event-mask
  • remote-programming-event-mask
  • rfidprogramming-event-mask

Expected result
ReportDataMesage should be displayed like below.
May 11 08:19:15 = chip-service[10172]: ReportDataMessage =
May 11 08:19:15 = chip-service[10172]: {
May 11 08:19:15 = chip-service[10172]: AttributeReportIBs =
May 11 08:19:15 = chip-service[10172]: [
May 11 08:19:15 = chip-service[10172]: AttributeReportIB =
May 11 08:19:15 = chip-service[10172]: {
May 11 08:19:15 = chip-service[10172]: AttributeDataIB =
May 11 08:19:15 = chip-service[10172]: {
May 11 08:19:15 = chip-service[10172]: DataVersion = 0xc5550562,
May 11 08:19:15 = chip-service[10172]: AttributePathIB =
May 11 08:19:15 = chip-service[10172]: {
May 11 08:19:15 = chip-service[10172]: Endpoint = 0x1,
May 11 08:19:15 = chip-service[10172]: Cluster = 0x101,
May 11 08:19:15 = chip-service[10172]: Attribute = 0x0000_0001,
May 11 08:19:15 = chip-service[10172]: }
May 11 08:19:15 = chip-service[10172]:
May 11 08:19:15 = chip-service[10172]: Data = 0,
May 11 08:19:15 = chip-service[10172]: },
May 11 08:19:15 = chip-service[10172]:
May 11 08:19:15 = chip-service[10172]: },
May 11 08:19:15 = chip-service[10172]:
May 11 08:19:15 = chip-service[10172]: ],
May 11 08:19:15 = chip-service[10172]:
May 11 08:19:15 = chip-service[10172]: SuppressResponse = true,
May 11 08:19:15 = chip-service[10172]: InteractionModelRevision = 1
May 11 08:19:15 = chip-service[10172]: }
May 11 08:19:15 = chip-service[10172]: ----------->Endpoint: 1 Cluster: 0x0000_0101 Attribute 0x0000_0001DataVersion: 3310683490
May 11 08:19:15 = chip-service[10172]: attributeValue: 0

Actual result
May 11 08:28:03 = chip-service[10172]: Response Failure: IM Error 0x00000586: General error: 0x86 (UNSUPPORTED_ATTRIBUTE)

Observation:
It is reproduced same using chip-tool on test harness.

TE9-TC-DL-3.1.txt

@bzbarsky-apple bzbarsky-apple added V1.0 app-clusters Application cluster work labels May 21, 2022
@bzbarsky-apple
Copy link
Contributor

It's probably better to use the example door lock app for testing door lock bits....

@bzbarsky-apple bzbarsky-apple added the spec Mismatch between spec and implementation label May 21, 2022
@cabin15
Copy link
Contributor Author

cabin15 commented May 23, 2022

@bzbarsky-apple
According to your comment, I did re-test with a few arguments in the below that already failed before, and it still failed with lock-app in the raspberrypi image provided for TE9 with 0xc3 (UNSUPPORTED_CLUSTER).

  • number-of-logs-records-supported
  • enable-logging
  • ledsettings
`############### Step 8 ###############`
ubuntu@ubuntu:~/apps$ ./chip-tool doorlock read number-of-log-records-supported 12345678 0
[1653286472.836288][2318:2318] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1653286472.836882][2318:2318] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1653286472.837059][2318:2318] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1653286472.837181][2318:2318] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1653286472.837489][2318:2318] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-YM0YDm)
[1653286472.838098][2318:2318] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1653286472.838153][2318:2318] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
[1653286472.839027][2318:2318] CHIP:DL: Got Ethernet interface: eth0
[1653286472.839701][2318:2318] CHIP:DL: Found the primary Ethernet interface:eth0
[1653286472.840291][2318:2318] CHIP:DL: Got WiFi interface: wlan0
[1653286472.846623][2318:2318] CHIP:DL: Found the primary WiFi interface:wlan0
[1653286472.846749][2318:2318] CHIP:IN: UDP::Init bind&listen port=0
[1653286472.846911][2318:2318] CHIP:IN: UDP::Init bound to port=35381
[1653286472.846943][2318:2318] CHIP:IN: BLEBase::Init - setting/overriding transport
[1653286472.846969][2318:2318] CHIP:IN: TransportMgr initialized
[1653286472.847037][2318:2318] CHIP:DIS: Init fabric pairing table with server storage
[1653286472.847210][2318:2318] CHIP:IN: Loading from storage for fabric index 0x1
[1653286472.850186][2318:2318] CHIP:IN: Loading from storage for fabric index 0x2
[1653286472.850964][2318:2318] CHIP:IN: Loading from storage for fabric index 0x3
[1653286472.851650][2318:2318] CHIP:DIS: Add fabric pairing table delegate
[1653286472.855299][2318:2318] CHIP:ZCL: Using ZAP configuration...
[1653286472.859843][2318:2318] CHIP:DL: Avahi client registered
[1653286472.861193][2318:2318] CHIP:CTL: System State Initialized...
[1653286472.861295][2318:2318] CHIP:CTL: Setting attestation nonce to random value
[1653286472.861353][2318:2318] CHIP:CTL: Setting CSR nonce to random value
[1653286472.861510][2318:2318] CHIP:CTL: Setting attestation nonce to random value
[1653286472.861578][2318:2318] CHIP:CTL: Setting CSR nonce to random value
[1653286472.862803][2318:2318] CHIP:CTL: Generating NOC
[1653286472.863886][2318:2318] CHIP:DIS: Verifying the received credentials
[1653286472.866296][2318:2318] CHIP:DIS: Added new fabric at index: 0x1, Initialized: 1
[1653286472.866346][2318:2318] CHIP:DIS: Assigned compressed fabric ID: 0xF2B50B84881A817F, node ID: 0x000000000001B669
[1653286472.866383][2318:2318] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xF2B50B84881A817F
[1653286472.866505][2318:2318] CHIP:CTL: Setting attestation nonce to random value
[1653286472.866604][2318:2318] CHIP:CTL: Setting CSR nonce to random value
[1653286472.867957][2318:2318] CHIP:CTL: Generating NOC
[1653286472.869254][2318:2318] CHIP:DIS: Verifying the received credentials
[1653286472.871868][2318:2318] CHIP:DIS: Added new fabric at index: 0x2, Initialized: 1
[1653286472.871918][2318:2318] CHIP:DIS: Assigned compressed fabric ID: 0x6E140C5E30387B82, node ID: 0x000000000001B669
[1653286472.871953][2318:2318] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x6E140C5E30387B82
[1653286472.872058][2318:2318] CHIP:CTL: Setting attestation nonce to random value
[1653286472.872157][2318:2318] CHIP:CTL: Setting CSR nonce to random value
[1653286472.873446][2318:2318] CHIP:CTL: Generating NOC
[1653286472.874799][2318:2318] CHIP:DIS: Verifying the received credentials
[1653286472.876987][2318:2318] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1
[1653286472.877021][2318:2318] CHIP:DIS: Assigned compressed fabric ID: 0xA86B7DD13FD4A011, node ID: 0x000000000001B669
[1653286472.877045][2318:2318] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xA86B7DD13FD4A011
[1653286472.907247][2318:2323] CHIP:DL: CHIP task running
[1653286472.907488][2318:2323] CHIP:DL: HandlePlatformSpecificBLEEvent 32787
[1653286472.907523][2318:2323] CHIP:TOO: Sending command to node 0xbc614e
[1653286472.907557][2318:2323] CHIP:CSM: FindOrEstablishSession: PeerId = F2B50B84881A817F:0000000000BC614E
[1653286472.907583][2318:2323] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found
[1653286472.907627][2318:2323] CHIP:DIS: Resolving F2B50B84881A817F:0000000000BC614E ...
[1653286472.909547][2318:2323] CHIP:DL: Avahi resolve found
[1653286472.909623][2318:2323] CHIP:DIS: Node ID resolved for F2B50B84881A817F:0000000000BC614E
[1653286472.909654][2318:2323] CHIP:DIS:     Addr 0: [fe80::dea6:32ff:fe02:887d]:5540
[1653286472.909903][2318:2323] CHIP:DIS: UDP:[fe80::dea6:32ff:fe02:887d%wlan0]:5540: new best score: 3
[1653286472.909931][2318:2323] CHIP:DIS: Checking node lookup status after 3 ms
[1653286472.909953][2318:2323] CHIP:DIS: Keeping DNSSD lookup active
[1653286473.107289][2318:2323] CHIP:DIS: Checking node lookup status after 200 ms
[1653286473.107470][2318:2323] CHIP:CTL: Updating device address to UDP:[fe80::dea6:32ff:fe02:887d%wlan0]:5540 while in state 1
[1653286473.107500][2318:2323] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 1 --> 2
[1653286473.107696][2318:2323] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000BC614E
[1653286473.108432][2318:2323] CHIP:SC: Including MRP parameters
[1653286473.108684][2318:2323] CHIP:IN: Prepared unauthenticated message 0xaaab1bb32e88 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 57049i with MessageCounter:2027985025.
[1653286473.108733][2318:2323] CHIP:IN: Sending unauthenticated msg 0xaaab1bb32e88 with MessageCounter:2027985025 to 0x0000000000000000 at monotonic time: 0000000000056D8E msec
[1653286473.108958][2318:2323] CHIP:SC: Sent Sigma1 msg
[1653286473.109018][2318:2323] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 2 --> 3
[1653286473.109047][2318:2323] CHIP:DIS: Discovery does not require any more timeouts
[1653286473.116300][2318:2323] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:1202191055 on exchange 57049i
[1653286473.116334][2318:2323] CHIP:EM: Found matching exchange: 57049i, Delegate: 0xffff940011b0
[1653286473.116373][2318:2323] CHIP:EM: Rxd Ack; Removing MessageCounter:2027985025 from Retrans Table on exchange 57049i
[1653286473.116397][2318:2323] CHIP:EM: Removed CHIP MessageCounter:2027985025 from RetransTable on exchange 57049i
[1653286473.116433][2318:2323] CHIP:SC: Received Sigma2Resume msg
[1653286473.116514][2318:2323] CHIP:SC: Found MRP parameters in the message
[1653286473.116541][2318:2323] CHIP:SC: Peer assigned session session ID 37981
[1653286473.121953][2318:2323] CHIP:SC: Sending status report. Protocol code 0, exchange 57049
[1653286473.122041][2318:2323] CHIP:EM: Piggybacking Ack for MessageCounter:1202191055 on exchange: 57049i
[1653286473.122109][2318:2323] CHIP:IN: Prepared unauthenticated message 0xaaab1bb32e88 to 0x0000000000000000 (0)  of type 0x40 and protocolId (0, 0) on exchange 57049i with MessageCounter:2027985026.
[1653286473.122177][2318:2323] CHIP:IN: Sending unauthenticated msg 0xaaab1bb32e88 with MessageCounter:2027985026 to 0x0000000000000000 at monotonic time: 0000000000056D9B msec
[1653286473.122562][2318:2323] CHIP:IN: New secure session created for device <0000000000BC614E, 1>, LSID:33093 PSID:37981!
[1653286473.122618][2318:2323] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 3 --> 4
[1653286473.122833][2318:2323] CHIP:TOO: Sending ReadAttribute to:
[1653286473.122880][2318:2323] CHIP:TOO: 	cluster 0x0000_0101, attribute: 0x0000_0010, endpoint 0
[1653286473.122935][2318:2323] CHIP:DMG: SendReadRequest ReadClient[0xffff940042c0]: Sending Read Request
[1653286473.123089][2318:2323] CHIP:IN: Prepared secure message 0xaaab1bb32ea8 to 0x0000000000BC614E (1)  of type 0x2 and protocolId (0, 1) on exchange 57050i with MessageCounter:15990585.
[1653286473.123151][2318:2323] CHIP:IN: Sending encrypted msg 0xaaab1bb32ea8 with MessageCounter:15990585 to 0x0000000000BC614E (1) at monotonic time: 0000000000056D9C msec
[1653286473.123406][2318:2323] CHIP:DMG: MoveToState ReadClient[0xffff940042c0]: Moving to [AwaitingIn]
[1653286473.134468][2318:2323] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:1202191056 on exchange 57049i
[1653286473.134523][2318:2323] CHIP:EM: Found matching exchange: 57049i, Delegate: (nil)
[1653286473.134586][2318:2323] CHIP:EM: Rxd Ack; Removing MessageCounter:2027985026 from Retrans Table on exchange 57049i
[1653286473.134624][2318:2323] CHIP:EM: Removed CHIP MessageCounter:2027985026 from RetransTable on exchange 57049i
[1653286473.137696][2318:2323] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:9218995 on exchange 57050i
[1653286473.137743][2318:2323] CHIP:EM: Found matching exchange: 57050i, Delegate: 0xffff940042c0
[1653286473.137793][2318:2323] CHIP:EM: Rxd Ack; Removing MessageCounter:15990585 from Retrans Table on exchange 57050i
[1653286473.137830][2318:2323] CHIP:EM: Removed CHIP MessageCounter:15990585 from RetransTable on exchange 57050i
[1653286473.137909][2318:2323] CHIP:DMG: ReportDataMessage =
[1653286473.137948][2318:2323] CHIP:DMG: {
[1653286473.137980][2318:2323] CHIP:DMG: 	AttributeReportIBs =
[1653286473.138027][2318:2323] CHIP:DMG: 	[
[1653286473.138062][2318:2323] CHIP:DMG: 		AttributeReportIB =
[1653286473.138114][2318:2323] CHIP:DMG: 		{
[1653286473.138155][2318:2323] CHIP:DMG: 			AttributeStatusIB =
[1653286473.138204][2318:2323] CHIP:DMG: 			{
[1653286473.138246][2318:2323] CHIP:DMG: 				AttributePathIB =
[1653286473.138296][2318:2323] CHIP:DMG: 				{
[1653286473.138347][2318:2323] CHIP:DMG: 					Endpoint = 0x0,
[1653286473.138398][2318:2323] CHIP:DMG: 					Cluster = 0x101,
[1653286473.138451][2318:2323] CHIP:DMG: 					Attribute = 0x0000_0010,
[1653286473.138503][2318:2323] CHIP:DMG: 				}
[1653286473.138558][2318:2323] CHIP:DMG: 					
[1653286473.138610][2318:2323] CHIP:DMG: 				StatusIB =
[1653286473.138664][2318:2323] CHIP:DMG: 				{
[1653286473.138745][2318:2323] CHIP:DMG: 					status = 0xc3 (UNSUPPORTED_CLUSTER),
[1653286473.138799][2318:2323] CHIP:DMG: 				},
[1653286473.138853][2318:2323] CHIP:DMG: 				
[1653286473.138901][2318:2323] CHIP:DMG: 			},
[1653286473.138952][2318:2323] CHIP:DMG: 			
[1653286473.138992][2318:2323] CHIP:DMG: 		},
[1653286473.139041][2318:2323] CHIP:DMG: 		
[1653286473.139079][2318:2323] CHIP:DMG: 	],
[1653286473.139124][2318:2323] CHIP:DMG: 	
[1653286473.139160][2318:2323] CHIP:DMG: 	SuppressResponse = true, 
[1653286473.139197][2318:2323] CHIP:DMG: 	InteractionModelRevision = 1
[1653286473.139232][2318:2323] CHIP:DMG: }
[1653286473.139379][2318:2323] CHIP:TOO: Response Failure: IM Error 0x000005C3: General error: 0xc3 (UNSUPPORTED_CLUSTER)
[1653286473.139483][2318:2323] CHIP:EM: Sending Standalone Ack for MessageCounter:9218995 on exchange 57050i
[1653286473.139565][2318:2323] CHIP:IN: Prepared secure message 0xffffa9728968 to 0x0000000000BC614E (1)  of type 0x10 and protocolId (0, 0) on exchange 57050i with MessageCounter:15990586.
[1653286473.139619][2318:2323] CHIP:IN: Sending encrypted msg 0xffffa9728968 with MessageCounter:15990586 to 0x0000000000BC614E (1) at monotonic time: 0000000000056DAC msec
[1653286473.139774][2318:2323] CHIP:EM: Flushed pending ack for MessageCounter:9218995 on exchange 57050i
[1653286473.140041][2318:2318] CHIP:CTL: Shutting down the commissioner
[1653286473.140091][2318:2318] CHIP:CTL: Shutting down the controller
[1653286473.140133][2318:2318] CHIP:CTL: Shutting down the commissioner
[1653286473.140168][2318:2318] CHIP:CTL: Shutting down the controller
[1653286473.140207][2318:2318] CHIP:IN: Expiring all connections for fabric 1!!
[1653286473.140271][2318:2318] CHIP:CTL: Shutting down the commissioner
[1653286473.140309][2318:2318] CHIP:CTL: Shutting down the controller
[1653286473.140339][2318:2318] CHIP:IN: Expiring all connections for fabric 2!!
[1653286473.140388][2318:2318] CHIP:CTL: Shutting down the commissioner
[1653286473.140422][2318:2318] CHIP:CTL: Shutting down the controller
[1653286473.140452][2318:2318] CHIP:IN: Expiring all connections for fabric 3!!
[1653286473.140495][2318:2318] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1653286473.141732][2318:2318] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286473.141787][2318:2318] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286473.141825][2318:2318] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286473.141858][2318:2318] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286473.141891][2318:2318] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1653286473.141986][2318:2318] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1653286473.142318][2318:2318] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Le3mzN)
[1653286473.143310][2318:2318] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1653286473.143403][2318:2318] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1653286473.143447][2318:2318] CHIP:DL: Inet Layer shutdown
[1653286473.143483][2318:2318] CHIP:DL: BLE shutdown
[1653286473.143519][2318:2318] CHIP:DL: System Layer shutdown
[1653286473.143700][2318:2318] CHIP:TOO: Run command failure: IM Error 0x000005C3: General error: 0xc3 (UNSUPPORTED_CLUSTER)
`############### Step 20 ###############`
ubuntu@ubuntu:~/apps$ ./chip-tool doorlock read enable-logging 12345678 0
[1653286809.898246][2350:2350] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1653286809.899034][2350:2350] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1653286809.899193][2350:2350] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1653286809.899303][2350:2350] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1653286809.899657][2350:2350] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-oOqD6P)
[1653286809.900291][2350:2350] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1653286809.900348][2350:2350] CHIP:DL: NVS set: chip-counters/reboot-count = 4 (0x4)
[1653286809.901208][2350:2350] CHIP:DL: Got Ethernet interface: eth0
[1653286809.901815][2350:2350] CHIP:DL: Found the primary Ethernet interface:eth0
[1653286809.902397][2350:2350] CHIP:DL: Got WiFi interface: wlan0
[1653286809.907827][2350:2350] CHIP:DL: Found the primary WiFi interface:wlan0
[1653286809.907944][2350:2350] CHIP:IN: UDP::Init bind&listen port=0
[1653286809.908102][2350:2350] CHIP:IN: UDP::Init bound to port=39243
[1653286809.908134][2350:2350] CHIP:IN: BLEBase::Init - setting/overriding transport
[1653286809.908160][2350:2350] CHIP:IN: TransportMgr initialized
[1653286809.908219][2350:2350] CHIP:DIS: Init fabric pairing table with server storage
[1653286809.908378][2350:2350] CHIP:IN: Loading from storage for fabric index 0x1
[1653286809.911443][2350:2350] CHIP:IN: Loading from storage for fabric index 0x2
[1653286809.912169][2350:2350] CHIP:IN: Loading from storage for fabric index 0x3
[1653286809.912845][2350:2350] CHIP:DIS: Add fabric pairing table delegate
[1653286809.916389][2350:2350] CHIP:ZCL: Using ZAP configuration...
[1653286809.920838][2350:2350] CHIP:DL: Avahi client registered
[1653286809.922168][2350:2350] CHIP:CTL: System State Initialized...
[1653286809.922260][2350:2350] CHIP:CTL: Setting attestation nonce to random value
[1653286809.922314][2350:2350] CHIP:CTL: Setting CSR nonce to random value
[1653286809.922440][2350:2350] CHIP:CTL: Setting attestation nonce to random value
[1653286809.922494][2350:2350] CHIP:CTL: Setting CSR nonce to random value
[1653286809.923499][2350:2350] CHIP:CTL: Generating NOC
[1653286809.924425][2350:2350] CHIP:DIS: Verifying the received credentials
[1653286809.926265][2350:2350] CHIP:DIS: Added new fabric at index: 0x1, Initialized: 1
[1653286809.926384][2350:2350] CHIP:DIS: Assigned compressed fabric ID: 0xF2B50B84881A817F, node ID: 0x000000000001B669
[1653286809.926412][2350:2350] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xF2B50B84881A817F
[1653286809.926511][2350:2350] CHIP:CTL: Setting attestation nonce to random value
[1653286809.926571][2350:2350] CHIP:CTL: Setting CSR nonce to random value
[1653286809.927406][2350:2350] CHIP:CTL: Generating NOC
[1653286809.928516][2350:2350] CHIP:DIS: Verifying the received credentials
[1653286809.930850][2350:2350] CHIP:DIS: Added new fabric at index: 0x2, Initialized: 1
[1653286809.930895][2350:2350] CHIP:DIS: Assigned compressed fabric ID: 0x6E140C5E30387B82, node ID: 0x000000000001B669
[1653286809.930927][2350:2350] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x6E140C5E30387B82
[1653286809.931024][2350:2350] CHIP:CTL: Setting attestation nonce to random value
[1653286809.931098][2350:2350] CHIP:CTL: Setting CSR nonce to random value
[1653286809.932093][2350:2350] CHIP:CTL: Generating NOC
[1653286809.933221][2350:2350] CHIP:DIS: Verifying the received credentials
[1653286809.935542][2350:2350] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1
[1653286809.935587][2350:2350] CHIP:DIS: Assigned compressed fabric ID: 0xA86B7DD13FD4A011, node ID: 0x000000000001B669
[1653286809.935620][2350:2350] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xA86B7DD13FD4A011
[1653286809.968464][2350:2355] CHIP:DL: CHIP task running
[1653286809.968717][2350:2355] CHIP:DL: HandlePlatformSpecificBLEEvent 32787
[1653286809.968751][2350:2355] CHIP:TOO: Sending command to node 0xbc614e
[1653286809.968785][2350:2355] CHIP:CSM: FindOrEstablishSession: PeerId = F2B50B84881A817F:0000000000BC614E
[1653286809.968811][2350:2355] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found
[1653286809.968854][2350:2355] CHIP:DIS: Resolving F2B50B84881A817F:0000000000BC614E ...
[1653286809.970635][2350:2355] CHIP:DL: Avahi resolve found
[1653286809.970747][2350:2355] CHIP:DIS: Node ID resolved for F2B50B84881A817F:0000000000BC614E
[1653286809.970783][2350:2355] CHIP:DIS:     Addr 0: [fe80::dea6:32ff:fe02:887d]:5540
[1653286809.971039][2350:2355] CHIP:DIS: UDP:[fe80::dea6:32ff:fe02:887d%wlan0]:5540: new best score: 3
[1653286809.971069][2350:2355] CHIP:DIS: Checking node lookup status after 2 ms
[1653286809.971091][2350:2355] CHIP:DIS: Keeping DNSSD lookup active
[1653286810.169519][2350:2355] CHIP:DIS: Checking node lookup status after 200 ms
[1653286810.169694][2350:2355] CHIP:CTL: Updating device address to UDP:[fe80::dea6:32ff:fe02:887d%wlan0]:5540 while in state 1
[1653286810.169722][2350:2355] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 1 --> 2
[1653286810.169918][2350:2355] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000BC614E
[1653286810.170648][2350:2355] CHIP:SC: Including MRP parameters
[1653286810.170926][2350:2355] CHIP:IN: Prepared unauthenticated message 0xaaaaf7c0b1c8 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 13104i with MessageCounter:1172931039.
[1653286810.171127][2350:2355] CHIP:IN: Sending unauthenticated msg 0xaaaaf7c0b1c8 with MessageCounter:1172931039 to 0x0000000000000000 at monotonic time: 00000000000A9234 msec
[1653286810.171492][2350:2355] CHIP:SC: Sent Sigma1 msg
[1653286810.171570][2350:2355] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 2 --> 3
[1653286810.171638][2350:2355] CHIP:DIS: Discovery does not require any more timeouts
[1653286810.180778][2350:2355] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:1202191059 on exchange 13104i
[1653286810.180857][2350:2355] CHIP:EM: Found matching exchange: 13104i, Delegate: 0xffff94001180
[1653286810.180943][2350:2355] CHIP:EM: Rxd Ack; Removing MessageCounter:1172931039 from Retrans Table on exchange 13104i
[1653286810.181003][2350:2355] CHIP:EM: Removed CHIP MessageCounter:1172931039 from RetransTable on exchange 13104i
[1653286810.181085][2350:2355] CHIP:SC: Received Sigma2Resume msg
[1653286810.181247][2350:2355] CHIP:SC: Found MRP parameters in the message
[1653286810.181314][2350:2355] CHIP:SC: Peer assigned session session ID 37983
[1653286810.187771][2350:2355] CHIP:SC: Sending status report. Protocol code 0, exchange 13104
[1653286810.187859][2350:2355] CHIP:EM: Piggybacking Ack for MessageCounter:1202191059 on exchange: 13104i
[1653286810.187926][2350:2355] CHIP:IN: Prepared unauthenticated message 0xaaaaf7c0b1c8 to 0x0000000000000000 (0)  of type 0x40 and protocolId (0, 0) on exchange 13104i with MessageCounter:1172931040.
[1653286810.187993][2350:2355] CHIP:IN: Sending unauthenticated msg 0xaaaaf7c0b1c8 with MessageCounter:1172931040 to 0x0000000000000000 at monotonic time: 00000000000A9245 msec
[1653286810.188339][2350:2355] CHIP:IN: New secure session created for device <0000000000BC614E, 1>, LSID:45314 PSID:37983!
[1653286810.188395][2350:2355] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 3 --> 4
[1653286810.188475][2350:2355] CHIP:TOO: Sending ReadAttribute to:
[1653286810.188516][2350:2355] CHIP:TOO: 	cluster 0x0000_0101, attribute: 0x0000_0020, endpoint 0
[1653286810.188568][2350:2355] CHIP:DMG: SendReadRequest ReadClient[0xffff94003fc0]: Sending Read Request
[1653286810.188716][2350:2355] CHIP:IN: Prepared secure message 0xaaaaf7c0b1e8 to 0x0000000000BC614E (1)  of type 0x2 and protocolId (0, 1) on exchange 13105i with MessageCounter:6656370.
[1653286810.188779][2350:2355] CHIP:IN: Sending encrypted msg 0xaaaaf7c0b1e8 with MessageCounter:6656370 to 0x0000000000BC614E (1) at monotonic time: 00000000000A9246 msec
[1653286810.188988][2350:2355] CHIP:DMG: MoveToState ReadClient[0xffff94003fc0]: Moving to [AwaitingIn]
[1653286810.262722][2350:2355] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:1202191060 on exchange 13104i
[1653286810.262808][2350:2355] CHIP:EM: Found matching exchange: 13104i, Delegate: (nil)
[1653286810.262908][2350:2355] CHIP:EM: Rxd Ack; Removing MessageCounter:1172931040 from Retrans Table on exchange 13104i
[1653286810.262970][2350:2355] CHIP:EM: Removed CHIP MessageCounter:1172931040 from RetransTable on exchange 13104i
[1653286810.263272][2350:2355] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:5293164 on exchange 13105i
[1653286810.263344][2350:2355] CHIP:EM: Found matching exchange: 13105i, Delegate: 0xffff94003fc0
[1653286810.263423][2350:2355] CHIP:EM: Rxd Ack; Removing MessageCounter:6656370 from Retrans Table on exchange 13105i
[1653286810.263482][2350:2355] CHIP:EM: Removed CHIP MessageCounter:6656370 from RetransTable on exchange 13105i
[1653286810.263605][2350:2355] CHIP:DMG: ReportDataMessage =
[1653286810.263671][2350:2355] CHIP:DMG: {
[1653286810.263724][2350:2355] CHIP:DMG: 	AttributeReportIBs =
[1653286810.263800][2350:2355] CHIP:DMG: 	[
[1653286810.263861][2350:2355] CHIP:DMG: 		AttributeReportIB =
[1653286810.263948][2350:2355] CHIP:DMG: 		{
[1653286810.264018][2350:2355] CHIP:DMG: 			AttributeStatusIB =
[1653286810.264089][2350:2355] CHIP:DMG: 			{
[1653286810.264147][2350:2355] CHIP:DMG: 				AttributePathIB =
[1653286810.264210][2350:2355] CHIP:DMG: 				{
[1653286810.264294][2350:2355] CHIP:DMG: 					Endpoint = 0x0,
[1653286810.264389][2350:2355] CHIP:DMG: 					Cluster = 0x101,
[1653286810.264484][2350:2355] CHIP:DMG: 					Attribute = 0x0000_0020,
[1653286810.264564][2350:2355] CHIP:DMG: 				}
[1653286810.264657][2350:2355] CHIP:DMG: 					
[1653286810.264743][2350:2355] CHIP:DMG: 				StatusIB =
[1653286810.264831][2350:2355] CHIP:DMG: 				{
[1653286810.264905][2350:2355] CHIP:DMG: 					status = 0xc3 (UNSUPPORTED_CLUSTER),
[1653286810.264986][2350:2355] CHIP:DMG: 				},
[1653286810.265061][2350:2355] CHIP:DMG: 				
[1653286810.265131][2350:2355] CHIP:DMG: 			},
[1653286810.265209][2350:2355] CHIP:DMG: 			
[1653286810.265272][2350:2355] CHIP:DMG: 		},
[1653286810.265347][2350:2355] CHIP:DMG: 		
[1653286810.265406][2350:2355] CHIP:DMG: 	],
[1653286810.265482][2350:2355] CHIP:DMG: 	
[1653286810.265542][2350:2355] CHIP:DMG: 	SuppressResponse = true, 
[1653286810.265603][2350:2355] CHIP:DMG: 	InteractionModelRevision = 1
[1653286810.265662][2350:2355] CHIP:DMG: }
[1653286810.265902][2350:2355] CHIP:TOO: Response Failure: IM Error 0x000005C3: General error: 0xc3 (UNSUPPORTED_CLUSTER)
[1653286810.266058][2350:2355] CHIP:EM: Sending Standalone Ack for MessageCounter:5293164 on exchange 13105i
[1653286810.266190][2350:2355] CHIP:IN: Prepared secure message 0xffffa8991968 to 0x0000000000BC614E (1)  of type 0x10 and protocolId (0, 0) on exchange 13105i with MessageCounter:6656371.
[1653286810.266276][2350:2355] CHIP:IN: Sending encrypted msg 0xffffa8991968 with MessageCounter:6656371 to 0x0000000000BC614E (1) at monotonic time: 00000000000A9293 msec
[1653286810.266500][2350:2355] CHIP:EM: Flushed pending ack for MessageCounter:5293164 on exchange 13105i
[1653286810.266943][2350:2350] CHIP:CTL: Shutting down the commissioner
[1653286810.267022][2350:2350] CHIP:CTL: Shutting down the controller
[1653286810.267080][2350:2350] CHIP:CTL: Shutting down the commissioner
[1653286810.267131][2350:2350] CHIP:CTL: Shutting down the controller
[1653286810.267195][2350:2350] CHIP:IN: Expiring all connections for fabric 1!!
[1653286810.267294][2350:2350] CHIP:CTL: Shutting down the commissioner
[1653286810.267354][2350:2350] CHIP:CTL: Shutting down the controller
[1653286810.267406][2350:2350] CHIP:IN: Expiring all connections for fabric 2!!
[1653286810.267484][2350:2350] CHIP:CTL: Shutting down the commissioner
[1653286810.267541][2350:2350] CHIP:CTL: Shutting down the controller
[1653286810.267591][2350:2350] CHIP:IN: Expiring all connections for fabric 3!!
[1653286810.267653][2350:2350] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1653286810.269627][2350:2350] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286810.269712][2350:2350] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286810.269765][2350:2350] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286810.269817][2350:2350] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286810.269869][2350:2350] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1653286810.270016][2350:2350] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1653286810.270464][2350:2350] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-GQ83Zm)
[1653286810.271876][2350:2350] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1653286810.272005][2350:2350] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1653286810.272137][2350:2350] CHIP:DL: Inet Layer shutdown
[1653286810.272195][2350:2350] CHIP:DL: BLE shutdown
[1653286810.272248][2350:2350] CHIP:DL: System Layer shutdown
[1653286810.272495][2350:2350] CHIP:TOO: Run command failure: IM Error 0x000005C3: General error: 0xc3 (UNSUPPORTED_CLUSTER)
`############### Step 22 ###############`
ubuntu@ubuntu:~/apps$ ./chip-tool doorlock read ledsettings 12345678 0
[1653286938.507358][2362:2362] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1653286938.507915][2362:2362] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1653286938.508090][2362:2362] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1653286938.508199][2362:2362] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1653286938.508569][2362:2362] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-SxFZaK)
[1653286938.509279][2362:2362] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1653286938.509335][2362:2362] CHIP:DL: NVS set: chip-counters/reboot-count = 5 (0x5)
[1653286938.510292][2362:2362] CHIP:DL: Got Ethernet interface: eth0
[1653286938.510934][2362:2362] CHIP:DL: Found the primary Ethernet interface:eth0
[1653286938.511603][2362:2362] CHIP:DL: Got WiFi interface: wlan0
[1653286938.518058][2362:2362] CHIP:DL: Found the primary WiFi interface:wlan0
[1653286938.518194][2362:2362] CHIP:IN: UDP::Init bind&listen port=0
[1653286938.518391][2362:2362] CHIP:IN: UDP::Init bound to port=33265
[1653286938.518428][2362:2362] CHIP:IN: BLEBase::Init - setting/overriding transport
[1653286938.518468][2362:2362] CHIP:IN: TransportMgr initialized
[1653286938.518540][2362:2362] CHIP:DIS: Init fabric pairing table with server storage
[1653286938.518787][2362:2362] CHIP:IN: Loading from storage for fabric index 0x1
[1653286938.522303][2362:2362] CHIP:IN: Loading from storage for fabric index 0x2
[1653286938.523244][2362:2362] CHIP:IN: Loading from storage for fabric index 0x3
[1653286938.524179][2362:2362] CHIP:DIS: Add fabric pairing table delegate
[1653286938.528289][2362:2362] CHIP:ZCL: Using ZAP configuration...
[1653286938.533090][2362:2362] CHIP:DL: Avahi client registered
[1653286938.534638][2362:2362] CHIP:CTL: System State Initialized...
[1653286938.534811][2362:2362] CHIP:CTL: Setting attestation nonce to random value
[1653286938.534876][2362:2362] CHIP:CTL: Setting CSR nonce to random value
[1653286938.534997][2362:2362] CHIP:CTL: Setting attestation nonce to random value
[1653286938.535054][2362:2362] CHIP:CTL: Setting CSR nonce to random value
[1653286938.536071][2362:2362] CHIP:CTL: Generating NOC
[1653286938.537083][2362:2362] CHIP:DIS: Verifying the received credentials
[1653286938.539005][2362:2362] CHIP:DIS: Added new fabric at index: 0x1, Initialized: 1
[1653286938.539055][2362:2362] CHIP:DIS: Assigned compressed fabric ID: 0xF2B50B84881A817F, node ID: 0x000000000001B669
[1653286938.539081][2362:2362] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0xF2B50B84881A817F
[1653286938.539193][2362:2362] CHIP:CTL: Setting attestation nonce to random value
[1653286938.539262][2362:2362] CHIP:CTL: Setting CSR nonce to random value
[1653286938.540132][2362:2362] CHIP:CTL: Generating NOC
[1653286938.541108][2362:2362] CHIP:DIS: Verifying the received credentials
[1653286938.542955][2362:2362] CHIP:DIS: Added new fabric at index: 0x2, Initialized: 1
[1653286938.543009][2362:2362] CHIP:DIS: Assigned compressed fabric ID: 0x6E140C5E30387B82, node ID: 0x000000000001B669
[1653286938.543034][2362:2362] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x6E140C5E30387B82
[1653286938.543128][2362:2362] CHIP:CTL: Setting attestation nonce to random value
[1653286938.543194][2362:2362] CHIP:CTL: Setting CSR nonce to random value
[1653286938.544039][2362:2362] CHIP:CTL: Generating NOC
[1653286938.545018][2362:2362] CHIP:DIS: Verifying the received credentials
[1653286938.546980][2362:2362] CHIP:DIS: Added new fabric at index: 0x3, Initialized: 1
[1653286938.547030][2362:2362] CHIP:DIS: Assigned compressed fabric ID: 0xA86B7DD13FD4A011, node ID: 0x000000000001B669
[1653286938.547055][2362:2362] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xA86B7DD13FD4A011
[1653286938.583466][2362:2367] CHIP:DL: CHIP task running
[1653286938.583718][2362:2367] CHIP:DL: HandlePlatformSpecificBLEEvent 32787
[1653286938.583752][2362:2367] CHIP:TOO: Sending command to node 0xbc614e
[1653286938.583783][2362:2367] CHIP:CSM: FindOrEstablishSession: PeerId = F2B50B84881A817F:0000000000BC614E
[1653286938.583810][2362:2367] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found
[1653286938.583854][2362:2367] CHIP:DIS: Resolving F2B50B84881A817F:0000000000BC614E ...
[1653286938.699023][2362:2367] CHIP:DL: Avahi resolve found
[1653286938.699127][2362:2367] CHIP:DIS: Node ID resolved for F2B50B84881A817F:0000000000BC614E
[1653286938.699172][2362:2367] CHIP:DIS:     Addr 0: [fe80::dea6:32ff:fe02:887d]:5540
[1653286938.699490][2362:2367] CHIP:DIS: UDP:[fe80::dea6:32ff:fe02:887d%wlan0]:5540: new best score: 3
[1653286938.699531][2362:2367] CHIP:DIS: Checking node lookup status after 115 ms
[1653286938.699562][2362:2367] CHIP:DIS: Keeping DNSSD lookup active
[1653286938.783996][2362:2367] CHIP:DIS: Checking node lookup status after 200 ms
[1653286938.784262][2362:2367] CHIP:CTL: Updating device address to UDP:[fe80::dea6:32ff:fe02:887d%wlan0]:5540 while in state 1
[1653286938.784325][2362:2367] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 1 --> 2
[1653286938.784711][2362:2367] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000BC614E
[1653286938.786178][2362:2367] CHIP:SC: Including MRP parameters
[1653286938.786625][2362:2367] CHIP:IN: Prepared unauthenticated message 0xaaaad250ba78 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 28814i with MessageCounter:2600356210.
[1653286938.786799][2362:2367] CHIP:IN: Sending unauthenticated msg 0xaaaad250ba78 with MessageCounter:2600356210 to 0x0000000000000000 at monotonic time: 00000000000C889C msec
[1653286938.787169][2362:2367] CHIP:SC: Sent Sigma1 msg
[1653286938.787240][2362:2367] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 2 --> 3
[1653286938.787308][2362:2367] CHIP:DIS: Discovery does not require any more timeouts
[1653286938.791426][2362:2367] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:1202191061 on exchange 28814i
[1653286938.791507][2362:2367] CHIP:EM: Found matching exchange: 28814i, Delegate: 0xffff94001180
[1653286938.791596][2362:2367] CHIP:EM: Rxd Ack; Removing MessageCounter:2600356210 from Retrans Table on exchange 28814i
[1653286938.791659][2362:2367] CHIP:EM: Removed CHIP MessageCounter:2600356210 from RetransTable on exchange 28814i
[1653286938.791741][2362:2367] CHIP:SC: Received Sigma2Resume msg
[1653286938.791908][2362:2367] CHIP:SC: Found MRP parameters in the message
[1653286938.791974][2362:2367] CHIP:SC: Peer assigned session session ID 37984
[1653286938.798488][2362:2367] CHIP:SC: Sending status report. Protocol code 0, exchange 28814
[1653286938.798555][2362:2367] CHIP:EM: Piggybacking Ack for MessageCounter:1202191061 on exchange: 28814i
[1653286938.798603][2362:2367] CHIP:IN: Prepared unauthenticated message 0xaaaad250ba78 to 0x0000000000000000 (0)  of type 0x40 and protocolId (0, 0) on exchange 28814i with MessageCounter:2600356211.
[1653286938.798651][2362:2367] CHIP:IN: Sending unauthenticated msg 0xaaaad250ba78 with MessageCounter:2600356211 to 0x0000000000000000 at monotonic time: 00000000000C88A7 msec
[1653286938.798958][2362:2367] CHIP:IN: New secure session created for device <0000000000BC614E, 1>, LSID:8543 PSID:37984!
[1653286938.798999][2362:2367] CHIP:CTL: OperationalDeviceProxy[F2B50B84881A817F:0000000000BC614E]: State change 3 --> 4
[1653286938.799057][2362:2367] CHIP:TOO: Sending ReadAttribute to:
[1653286938.799084][2362:2367] CHIP:TOO: 	cluster 0x0000_0101, attribute: 0x0000_0022, endpoint 0
[1653286938.799121][2362:2367] CHIP:DMG: SendReadRequest ReadClient[0xffff94004020]: Sending Read Request
[1653286938.799230][2362:2367] CHIP:IN: Prepared secure message 0xaaaad250ba98 to 0x0000000000BC614E (1)  of type 0x2 and protocolId (0, 1) on exchange 28815i with MessageCounter:3568760.
[1653286938.799273][2362:2367] CHIP:IN: Sending encrypted msg 0xaaaad250ba98 with MessageCounter:3568760 to 0x0000000000BC614E (1) at monotonic time: 00000000000C88A8 msec
[1653286938.799407][2362:2367] CHIP:DMG: MoveToState ReadClient[0xffff94004020]: Moving to [AwaitingIn]
[1653286938.811713][2362:2367] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:1202191062 on exchange 28814i
[1653286938.811752][2362:2367] CHIP:EM: Found matching exchange: 28814i, Delegate: (nil)
[1653286938.811799][2362:2367] CHIP:EM: Rxd Ack; Removing MessageCounter:2600356211 from Retrans Table on exchange 28814i
[1653286938.811826][2362:2367] CHIP:EM: Removed CHIP MessageCounter:2600356211 from RetransTable on exchange 28814i
[1653286938.812819][2362:2367] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:14098154 on exchange 28815i
[1653286938.812871][2362:2367] CHIP:EM: Found matching exchange: 28815i, Delegate: 0xffff94004020
[1653286938.812927][2362:2367] CHIP:EM: Rxd Ack; Removing MessageCounter:3568760 from Retrans Table on exchange 28815i
[1653286938.812967][2362:2367] CHIP:EM: Removed CHIP MessageCounter:3568760 from RetransTable on exchange 28815i
[1653286938.813052][2362:2367] CHIP:DMG: ReportDataMessage =
[1653286938.813096][2362:2367] CHIP:DMG: {
[1653286938.813131][2362:2367] CHIP:DMG: 	AttributeReportIBs =
[1653286938.813182][2362:2367] CHIP:DMG: 	[
[1653286938.813222][2362:2367] CHIP:DMG: 		AttributeReportIB =
[1653286938.813281][2362:2367] CHIP:DMG: 		{
[1653286938.813324][2362:2367] CHIP:DMG: 			AttributeStatusIB =
[1653286938.813377][2362:2367] CHIP:DMG: 			{
[1653286938.813425][2362:2367] CHIP:DMG: 				AttributePathIB =
[1653286938.813479][2362:2367] CHIP:DMG: 				{
[1653286938.813540][2362:2367] CHIP:DMG: 					Endpoint = 0x0,
[1653286938.813602][2362:2367] CHIP:DMG: 					Cluster = 0x101,
[1653286938.813665][2362:2367] CHIP:DMG: 					Attribute = 0x0000_0022,
[1653286938.813720][2362:2367] CHIP:DMG: 				}
[1653286938.813781][2362:2367] CHIP:DMG: 					
[1653286938.813828][2362:2367] CHIP:DMG: 				StatusIB =
[1653286938.813873][2362:2367] CHIP:DMG: 				{
[1653286938.813929][2362:2367] CHIP:DMG: 					status = 0xc3 (UNSUPPORTED_CLUSTER),
[1653286938.813982][2362:2367] CHIP:DMG: 				},
[1653286938.814037][2362:2367] CHIP:DMG: 				
[1653286938.814084][2362:2367] CHIP:DMG: 			},
[1653286938.814144][2362:2367] CHIP:DMG: 			
[1653286938.814189][2362:2367] CHIP:DMG: 		},
[1653286938.814243][2362:2367] CHIP:DMG: 		
[1653286938.814282][2362:2367] CHIP:DMG: 	],
[1653286938.814333][2362:2367] CHIP:DMG: 	
[1653286938.814372][2362:2367] CHIP:DMG: 	SuppressResponse = true, 
[1653286938.814413][2362:2367] CHIP:DMG: 	InteractionModelRevision = 1
[1653286938.814451][2362:2367] CHIP:DMG: }
[1653286938.814619][2362:2367] CHIP:TOO: Response Failure: IM Error 0x000005C3: General error: 0xc3 (UNSUPPORTED_CLUSTER)
[1653286938.814767][2362:2367] CHIP:EM: Sending Standalone Ack for MessageCounter:14098154 on exchange 28815i
[1653286938.814861][2362:2367] CHIP:IN: Prepared secure message 0xffffa9e90968 to 0x0000000000BC614E (1)  of type 0x10 and protocolId (0, 0) on exchange 28815i with MessageCounter:3568761.
[1653286938.814922][2362:2367] CHIP:IN: Sending encrypted msg 0xffffa9e90968 with MessageCounter:3568761 to 0x0000000000BC614E (1) at monotonic time: 00000000000C88B8 msec
[1653286938.815083][2362:2367] CHIP:EM: Flushed pending ack for MessageCounter:14098154 on exchange 28815i
[1653286938.815353][2362:2362] CHIP:CTL: Shutting down the commissioner
[1653286938.815413][2362:2362] CHIP:CTL: Shutting down the controller
[1653286938.815458][2362:2362] CHIP:CTL: Shutting down the commissioner
[1653286938.815497][2362:2362] CHIP:CTL: Shutting down the controller
[1653286938.815541][2362:2362] CHIP:IN: Expiring all connections for fabric 1!!
[1653286938.815608][2362:2362] CHIP:CTL: Shutting down the commissioner
[1653286938.815650][2362:2362] CHIP:CTL: Shutting down the controller
[1653286938.815685][2362:2362] CHIP:IN: Expiring all connections for fabric 2!!
[1653286938.815738][2362:2362] CHIP:CTL: Shutting down the commissioner
[1653286938.815778][2362:2362] CHIP:CTL: Shutting down the controller
[1653286938.815811][2362:2362] CHIP:IN: Expiring all connections for fabric 3!!
[1653286938.815860][2362:2362] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1653286938.817224][2362:2362] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286938.817291][2362:2362] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286938.817320][2362:2362] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286938.817347][2362:2362] CHIP:DMG: IM WH moving to [Uninitialized]
[1653286938.817376][2362:2362] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1653286938.817471][2362:2362] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1653286938.817808][2362:2362] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-pdy8ID)
[1653286938.818829][2362:2362] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1653286938.818932][2362:2362] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1653286938.818977][2362:2362] CHIP:DL: Inet Layer shutdown
[1653286938.819014][2362:2362] CHIP:DL: BLE shutdown
[1653286938.819051][2362:2362] CHIP:DL: System Layer shutdown
[1653286938.819243][2362:2362] CHIP:TOO: Run command failure: IM Error 0x000005C3: General error: 0xc3 (UNSUPPORTED_CLUSTER)`

@bzbarsky-apple
Copy link
Contributor

@cabin15 Thank you! Those are definitely wrong: they should either succeed or return UNSUPPORTED_ATTRIBUTE...

@bzbarsky-apple
Copy link
Contributor

And to be clear, these are optional attributes, so the tests should allow them to not exist.

@cjandhyala can you please make sure the test plans handle these attributes being missing (including the LOG feature not being supported) properly?

@cjandhyala
Copy link
Contributor

@bzbarsky-apple @andy31415 , the test plan needs to be updated. Not a SDK issue. @cabin15 pls chk with the test plan owner and close the issue.

@woody-apple
Copy link
Contributor

SDK Spec Review: Assigning to @bzbarsky-apple to update lock items.

bzbarsky-apple added a commit to bzbarsky-apple/connectedhomeip that referenced this issue Jun 1, 2022
* The LOG feature is "[Zigbee]" in the device library, and the Door Lock cluster
  spec says: "If Events are supported the logging feature SHALL NOT be
  supported.".  That means the following attributes are not part of Matter:

  * NumberOfLogRecordsSupported
  * EnableLogging

  and neither are the following commands:

  * Get Log Record
  * Get Log Record Response

* The NOT feature is "[Zigbee]" in the device library.  Again, events replace it
  in Matter.  That means the following attributes are not part of Matter:

  * KeypadOperationEventMask
  * RemoteOperationEventMask
  * ManualOperationEventMask
  * RFIDOperationEventMask
  * KeypadProgrammingEventMask
  * RemoteProgrammingEventMask
  * RFIDProgrammingEventMask

  and neither are the following commands:

  * Operating Event Notification
  * Programming Event Notification

* The Alarms conformance is Zigbee-only in the device library, so the AlarmMask
  attribute is not part of Matter.

* The USR feature is required in Matter if any of PIN, RID, FPG, FACE are
  supported.  That means anything conditioned on !USR and those features is not
  part of Matter.  Specifically, that is the following commands:

  * Set PIN Code
  * Get PIN Code
  * Get PIN Code Response
  * Clear PIN Code
  * Clear All PIN Codes
  * Set User Status
  * Get User Status
  * Get User Status Response
  * Set User Type
  * Get User Type
  * Get User Type Response
  * Set RFID Code
  * Get RFID Code
  * Get RFID Code Response
  * Clear RFID Code
  * Clear All RFID Codes

Fixes project-chip#18492 by
making it clear that these are not part of Matter and hence not to be
tested in Matter certification.
bzbarsky-apple added a commit to bzbarsky-apple/connectedhomeip that referenced this issue Jun 2, 2022
* The LOG feature is "[Zigbee]" in the device library, and the Door Lock cluster
  spec says: "If Events are supported the logging feature SHALL NOT be
  supported.".  That means the following attributes are not part of Matter:

  * NumberOfLogRecordsSupported
  * EnableLogging

  and neither are the following commands:

  * Get Log Record
  * Get Log Record Response

* The NOT feature is "[Zigbee]" in the device library.  Again, events replace it
  in Matter.  That means the following attributes are not part of Matter:

  * KeypadOperationEventMask
  * RemoteOperationEventMask
  * ManualOperationEventMask
  * RFIDOperationEventMask
  * KeypadProgrammingEventMask
  * RemoteProgrammingEventMask
  * RFIDProgrammingEventMask

  and neither are the following commands:

  * Operating Event Notification
  * Programming Event Notification

* The Alarms conformance is Zigbee-only in the device library, so the AlarmMask
  attribute is not part of Matter.

* The USR feature is required in Matter if any of PIN, RID, FPG, FACE are
  supported.  That means anything conditioned on !USR and those features is not
  part of Matter.  Specifically, that is the following commands:

  * Set PIN Code
  * Get PIN Code
  * Get PIN Code Response
  * Clear PIN Code
  * Clear All PIN Codes
  * Set User Status
  * Get User Status
  * Get User Status Response
  * Set User Type
  * Get User Type
  * Get User Type Response
  * Set RFID Code
  * Get RFID Code
  * Get RFID Code Response
  * Clear RFID Code
  * Clear All RFID Codes

Fixes project-chip#18492 by
making it clear that these are not part of Matter and hence not to be
tested in Matter certification.
bzbarsky-apple added a commit to bzbarsky-apple/connectedhomeip that referenced this issue Jun 2, 2022
* The LOG feature is "[Zigbee]" in the device library, and the Door Lock cluster
  spec says: "If Events are supported the logging feature SHALL NOT be
  supported.".  That means the following attributes are not part of Matter:

  * NumberOfLogRecordsSupported
  * EnableLogging

  and neither are the following commands:

  * Get Log Record
  * Get Log Record Response

* The NOT feature is "[Zigbee]" in the device library.  Again, events replace it
  in Matter.  That means the following attributes are not part of Matter:

  * KeypadOperationEventMask
  * RemoteOperationEventMask
  * ManualOperationEventMask
  * RFIDOperationEventMask
  * KeypadProgrammingEventMask
  * RemoteProgrammingEventMask
  * RFIDProgrammingEventMask

  and neither are the following commands:

  * Operating Event Notification
  * Programming Event Notification

* The Alarms conformance is Zigbee-only in the device library, so the AlarmMask
  attribute is not part of Matter.

* The USR feature is required in Matter if any of PIN, RID, FPG, FACE are
  supported.  That means anything conditioned on !USR and those features is not
  part of Matter.  Specifically, that is the following commands:

  * Set PIN Code
  * Get PIN Code
  * Get PIN Code Response
  * Clear PIN Code
  * Clear All PIN Codes
  * Set User Status
  * Get User Status
  * Get User Status Response
  * Set User Type
  * Get User Type
  * Get User Type Response
  * Set RFID Code
  * Get RFID Code
  * Get RFID Code Response
  * Clear RFID Code
  * Clear All RFID Codes

Fixes project-chip#18492 by
making it clear that these are not part of Matter and hence not to be
tested in Matter certification.
andy31415 pushed a commit that referenced this issue Jun 2, 2022
* The LOG feature is "[Zigbee]" in the device library, and the Door Lock cluster
  spec says: "If Events are supported the logging feature SHALL NOT be
  supported.".  That means the following attributes are not part of Matter:

  * NumberOfLogRecordsSupported
  * EnableLogging

  and neither are the following commands:

  * Get Log Record
  * Get Log Record Response

* The NOT feature is "[Zigbee]" in the device library.  Again, events replace it
  in Matter.  That means the following attributes are not part of Matter:

  * KeypadOperationEventMask
  * RemoteOperationEventMask
  * ManualOperationEventMask
  * RFIDOperationEventMask
  * KeypadProgrammingEventMask
  * RemoteProgrammingEventMask
  * RFIDProgrammingEventMask

  and neither are the following commands:

  * Operating Event Notification
  * Programming Event Notification

* The Alarms conformance is Zigbee-only in the device library, so the AlarmMask
  attribute is not part of Matter.

* The USR feature is required in Matter if any of PIN, RID, FPG, FACE are
  supported.  That means anything conditioned on !USR and those features is not
  part of Matter.  Specifically, that is the following commands:

  * Set PIN Code
  * Get PIN Code
  * Get PIN Code Response
  * Clear PIN Code
  * Clear All PIN Codes
  * Set User Status
  * Get User Status
  * Get User Status Response
  * Set User Type
  * Get User Type
  * Get User Type Response
  * Set RFID Code
  * Get RFID Code
  * Get RFID Code Response
  * Clear RFID Code
  * Clear All RFID Codes

Fixes #18492 by
making it clear that these are not part of Matter and hence not to be
tested in Matter certification.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
app-clusters Application cluster work spec Mismatch between spec and implementation V1.0
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants