text:
TC-IDM-6.4 chip tool Darwin testing: Eventrequests and EventFilters were missing in the response for step 1

As per step 1 in TC-IDM-6.4, the response should contain EventRequests and EventFilters, but the response for subscribe were missing these fields. Below is the expected outcome.

Below is the outcome for the command - ./chip-tool-darwin thermostat subscribe cluster-revision 1 10 1 1 1

Controller side log:
adk@adks-Mac-mini debug % ./chip-tool-darwin thermostat subscribe cluster-revision 1 10 1 1 1
[1648065573359] [39479:3699021] CHIP: [TOO] Running Command
2022-03-23 12:59:33.363 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: ChipToolOpCredsCAKey, value BAG6TxndA16E328KB+s67FX9+5LHU3I7cBrMiHJcajq1An4MxepBioxfnjaunMfI0vAeiWTeGU8HTgmQJVfHOAVnEv1hZWowEttLnZKxu5hy5AIn9FY0u9QOq48M2kXqmA==
2022-03-23 12:59:33.365 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: com.zigbee.chip.commissioner.device_id
2022-03-23 12:59:33.365 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: com.zigbee.chip.commissioner.device_id, value Gr6DOjXiCDA=
2022-03-23 12:59:33.366 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: MatterCARootCert0
2022-03-23 12:59:33.366 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: MatterCARootCert0, value MIIB2TCCAYCgAwIBAgIBADAKBggqhkjOPQQDAjBEMSAwHgYKKwYBBAGConwBBAwQMDAwMDAwMDAwMDAwMDREMjEgMB4GCisGAQQBgqJ8AQUMEDAwMDAwMDAwMDAwMDAwMDAwHhcNMjIwMzA4MTUwMDAxWhcNMjMwMzA4MTUwMDAxWjBEMSAwHgYKKwYBBAGConwBBAwQMDAwMDAwMDAwMDAwMDREMjEgMB4GCisGAQQBgqJ8AQUMEDAwMDAwMDAwMDAwMDAwMDAwWTATBgcqhkjOPQIBBggqhkjOPQMBBwNCAAQBuk8Z3QNehN9vCgfrOuxV/fuSx1NyO3AazIhyXGo6tQJ+DMXqQYqMX542rpzHyNLwHolk3hlPB04JkCVXxzgFo2MwYTAPBgNVHRMBAf8EBTADAQH/MA4GA1UdDwEB/wQEAwIBBjAdBgNVHQ4EFgQUpAxXUsDrlQkg7iOO2exDAIyjA7wwHwYDVR0jBBgwFoAUpAxXUsDrlQkg7iOO2exDAIyjA7wwCgYIKoZIzj0EAwIDRwAwRAIgQUDQA6aWAftkPOHso2ZV3++c1BRhHsD1MZ3vK0lauJcCIEZEVgTELLz7k+XFXsETqa4U1jXFK3GF+Zyi2DvqqfmU
[1648065573366] [39479:3699021] CHIP: [DL] KVS will be written to: file:///tmp/chip_kvs
[1648065573373] [39479:3699021] CHIP: [DL] _Init
[1648065573373] [39479:3699021] CHIP: [IN] UDP::Init bind&listen port=5541
[1648065573375] [39479:3699021] CHIP: [IN] UDP::Init bound to port=5541
[1648065573375] [39479:3699021] CHIP: [IN] UDP::Init bind&listen port=5541
[1648065573375] [39479:3699021] CHIP: [IN] UDP::Init bound to port=5541
[1648065573375] [39479:3699021] CHIP: [IN] TransportMgr initialized
[1648065573375] [39479:3699021] CHIP: [DIS] Init fabric pairing table with server storage
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F01/Fabric1
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F01/Fabric1, value AQAAAAAAAAAavoM6NeIIMAAAAAAAAAAAAADvAAAA/AAE4DFh8ZQ0tNQWhy2zZhR7hKLLXtBT7c4nqAys8VsPVAmVfY4IWOkwCGvh7S16/4xP1mPfxNJWTSXpsM8kaIYYrwE1VKTVzrgo21ldtxwiPn8R9I81i2JRVt1bLMfrqwYlAAAAAAAAAGEAAAAAAAAAFTABAQAkAgE3AyUU0gQkFQAYJgTxK7opJgVxX5srNwYlFNIEJBUAGCQHASQIATAJQQQBuk8Z3QNehN9vCgfrOuxV/fuSx1NyO3AazIhyXGo6tQJ+DMXqQYqMX542rpzHyNLwHolk3hlPB04JkCVXxzgFNwo1ASkBGCQCYDAEFKQMV1LA65UJIO4jjtnsQwCMowO8MAUUpAxXUsDrlQkg7iOO2exDAIyjA7wYMAtAQUDQA6aWAftkPOHso2ZV3++c1BRhHsD1MZ3vK0lauJdGRFYExCy8+5PlxV7BE6muFNY1xStxhfmcotg76qn5lBgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAVMAEBASQCATcDJRTSBCQVABgmBPEruikmBXFfmys3BiQVACcRGr6DOjXiCDAYJAcBJAgBMAlBBOAxYfGUNLTUFocts2YUe4Siy17QU+3OJ6gMrPFbD1QJlX2OCFjpMAhr4e0tev+MT9Zj38TSVk0l6bDPJGiGGK83CjUBKAEYJAIBNgMEAgQBGDAEFE5MrUA6J9TLEXIDswqDh+XQhN25MAUUpAxXUsDrlQkg7iOO2exDAIyjA7wYMAtAwaRsIg0BJ16NFDi9Tei62tsnhrhlv/DGr3JxPjTx+MDE1m1JyVObAGfLE4fUlLHz7sNhWEgCBjqEi5ZNR6ZVQRgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==
[1648065573375] [39479:3699021] CHIP: [IN] Loading certs from storage
[1648065573375] [39479:3699021] CHIP: [IN] Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
[1648065573375] [39479:3699021] CHIP: [IN] 0x04, 0x01, 0xba, 0x4f, 0x19, 0xdd, 0x03, 0x5e,
[1648065573375] [39479:3699021] CHIP: [IN] 0x84, 0xdf, 0x6f, 0x0a, 0x07, 0xeb, 0x3a, 0xec,
[1648065573375] [39479:3699021] CHIP: [IN] 0x55, 0xfd, 0xfb, 0x92, 0xc7, 0x53, 0x72, 0x3b,
[1648065573375] [39479:3699021] CHIP: [IN] 0x70, 0x1a, 0xcc, 0x88, 0x72, 0x5c, 0x6a, 0x3a,
[1648065573375] [39479:3699021] CHIP: [IN] 0xb5, 0x02, 0x7e, 0x0c, 0xc5, 0xea, 0x41, 0x8a,
[1648065573375] [39479:3699021] CHIP: [IN] 0x8c, 0x5f, 0x9e, 0x36, 0xae, 0x9c, 0xc7, 0xc8,
[1648065573375] [39479:3699021] CHIP: [IN] 0xd2, 0xf0, 0x1e, 0x89, 0x64, 0xde, 0x19, 0x4f,
[1648065573375] [39479:3699021] CHIP: [IN] 0x07, 0x4e, 0x09, 0x90, 0x25, 0x57, 0xc7, 0x38,
[1648065573375] [39479:3699021] CHIP: [IN] 0x05,
[1648065573375] [39479:3699021] CHIP: [IN] Generated compressed fabric ID
[1648065573375] [39479:3699021] CHIP: [IN] 0xd0, 0x99, 0xe4, 0x0d, 0x93, 0xb1, 0xdc, 0x0c,
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F02/Fabric2
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F02/Fabric2, value (null)
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F03/Fabric3
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F03/Fabric3, value (null)
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F04/Fabric4
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F04/Fabric4, value (null)
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F05/Fabric5
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F05/Fabric5, value (null)
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F06/Fabric6
2022-03-23 12:59:33.375 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F06/Fabric6, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F07/Fabric7
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F07/Fabric7, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F08/Fabric8
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F08/Fabric8, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F09/Fabric9
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F09/Fabric9, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F0A/Fabrica
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F0A/Fabrica, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F0B/Fabricb
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F0B/Fabricb, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F0C/Fabricc
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F0C/Fabricc, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F0D/Fabricd
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F0D/Fabricd, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F0E/Fabrice
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F0E/Fabrice, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F0F/Fabricf
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F0F/Fabricf, value (null)
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: F10/Fabric10
2022-03-23 12:59:33.376 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: F10/Fabric10, value (null)
2022-03-23 12:59:33.377 chip-tool-darwin[39479:3699021] PersistentStorageDelegate Sync Get Value for Key: gcc
2022-03-23 12:59:33.377 chip-tool-darwin[39479:3699021] CHIPPersistentStorageDelegate Get Value for Key: gcc, value (null)
[1648065573377] [39479:3699021] CHIP: [ZCL] Using ZAP configuration...
[1648065573377] [39479:3699021] CHIP: [CTL] System State Initialized...
[1648065573377] [39479:3699021] CHIP: [CTL] Intermediate CA is not needed
[1648065573378] [39479:3699021] CHIP: [DIS] Verifying the received credentials
[1648065573378] [39479:3699021] CHIP: [IN] Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
[1648065573378] [39479:3699021] CHIP: [IN] 0x04, 0x01, 0xba, 0x4f, 0x19, 0xdd, 0x03, 0x5e,
[1648065573378] [39479:3699021] CHIP: [IN] 0x84, 0xdf, 0x6f, 0x0a, 0x07, 0xeb, 0x3a, 0xec,
[1648065573378] [39479:3699021] CHIP: [IN] 0x55, 0xfd, 0xfb, 0x92, 0xc7, 0x53, 0x72, 0x3b,
[1648065573378] [39479:3699021] CHIP: [IN] 0x70, 0x1a, 0xcc, 0x88, 0x72, 0x5c, 0x6a, 0x3a,
[1648065573378] [39479:3699021] CHIP: [IN] 0xb5, 0x02, 0x7e, 0x0c, 0xc5, 0xea, 0x41, 0x8a,
[1648065573378] [39479:3699021] CHIP: [IN] 0x8c, 0x5f, 0x9e, 0x36, 0xae, 0x9c, 0xc7, 0xc8,
[1648065573378] [39479:3699021] CHIP: [IN] 0xd2, 0xf0, 0x1e, 0x89, 0x64, 0xde, 0x19, 0x4f,
[1648065573378] [39479:3699021] CHIP: [IN] 0x07, 0x4e, 0x09, 0x90, 0x25, 0x57, 0xc7, 0x38,
[1648065573378] [39479:3699021] CHIP: [IN] 0x05,
[1648065573378] [39479:3699021] CHIP: [IN] Generated compressed fabric ID
[1648065573378] [39479:3699021] CHIP: [IN] 0xd0, 0x99, 0xe4, 0x0d, 0x93, 0xb1, 0xdc, 0x0c,
[1648065573378] [39479:3699021] CHIP: [DIS] Added new fabric at index: 1, Initialized: 1
[1648065573378] [39479:3699021] CHIP: [DIS] Assigned compressed fabric ID: 0xD099E40D93B1DC0C, node ID: 0x3008E2353A83BE1A
[1648065573378] [39479:3699021] CHIP: [CTL] Joined the fabric at index 1. Compressed fabric ID is: 0xD099E40D93B1DC0C
[1648065573378] [39479:3699021] CHIP: [TOO] Sending command to node 0x0000000000000001
[1648065573378] [39479:3699024] CHIP: [DL] _OnPlatformEvent
[1648065573379] [39479:3699024] CHIP: [DL] Resolved interface id: 8
[1648065573380] [39479:3699024] CHIP: [DL] Mdns: OnGetAddrInfo hostname:E45F012EED540000.local.
[1648065573380] [39479:3699024] CHIP: [DL] Mdns: OnGetAddrInfo hostname:E45F012EED540000.local.
[1648065573380] [39479:3699024] CHIP: [DIS] Node ID resolved for 0x0000000000000001
[1648065573380] [39479:3699024] CHIP: [DIS]     Addr 0: [fe80::e65f:1ff:fe2e:ed54]:5540
[1648065573380] [39479:3699024] CHIP: [DIS]     Addr 1: [192.168.1.100]:5540
[1648065573380] [39479:3699024] CHIP: [CTL] OperationalDiscoveryComplete for device ID 0x0000000000000001
[1648065573380] [39479:3699024] CHIP: [IN] Generating DestinationID. Fabric ID 0x0000000000000000, Dest node ID 0x0000000000000001, Random data
[1648065573380] [39479:3699024] CHIP: [IN] 0x56, 0xd5, 0x7c, 0x2a, 0xe0, 0x87, 0x44, 0xe5,
[1648065573380] [39479:3699024] CHIP: [IN] 0xff, 0xb5, 0x1a, 0x4a, 0xb0, 0xd9, 0xf2, 0x1b,
[1648065573380] [39479:3699024] CHIP: [IN] 0xf4, 0x37, 0xd8, 0x85, 0xf5, 0x05, 0xbd, 0x4c,
[1648065573380] [39479:3699024] CHIP: [IN] 0x3c, 0x68, 0xa9, 0xe9, 0xc4, 0x32, 0x24, 0x83,
[1648065573380] [39479:3699024] CHIP: [IN] Root pubkey
[1648065573380] [39479:3699024] CHIP: [IN] 0x04, 0x01, 0xba, 0x4f, 0x19, 0xdd, 0x03, 0x5e,
[1648065573380] [39479:3699024] CHIP: [IN] 0x84, 0xdf, 0x6f, 0x0a, 0x07, 0xeb, 0x3a, 0xec,
[1648065573380] [39479:3699024] CHIP: [IN] 0x55, 0xfd, 0xfb, 0x92, 0xc7, 0x53, 0x72, 0x3b,
[1648065573380] [39479:3699024] CHIP: [IN] 0x70, 0x1a, 0xcc, 0x88, 0x72, 0x5c, 0x6a, 0x3a,
[1648065573380] [39479:3699024] CHIP: [IN] 0xb5, 0x02, 0x7e, 0x0c, 0xc5, 0xea, 0x41, 0x8a,
[1648065573380] [39479:3699024] CHIP: [IN] 0x8c, 0x5f, 0x9e, 0x36, 0xae, 0x9c, 0xc7, 0xc8,
[1648065573380] [39479:3699024] CHIP: [IN] 0xd2, 0xf0, 0x1e, 0x89, 0x64, 0xde, 0x19, 0x4f,
[1648065573380] [39479:3699024] CHIP: [IN] 0x07, 0x4e, 0x09, 0x90, 0x25, 0x57, 0xc7, 0x38,
[1648065573380] [39479:3699024] CHIP: [IN] 0x05,
[1648065573380] [39479:3699024] CHIP: [IN] IPK
[1648065573380] [39479:3699024] CHIP: [IN] 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
[1648065573380] [39479:3699024] CHIP: [IN] 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
[1648065573380] [39479:3699024] CHIP: [IN] Generated DestinationID output
[1648065573380] [39479:3699024] CHIP: [IN] 0x04, 0xe1, 0x08, 0xa2, 0x15, 0xf6, 0x00, 0x4b,
[1648065573380] [39479:3699024] CHIP: [IN] 0x7e, 0x7c, 0x09, 0xd5, 0xfd, 0x54, 0xd1, 0x72,
[1648065573380] [39479:3699024] CHIP: [IN] 0xed, 0x84, 0x36, 0x58, 0x05, 0x14, 0x3a, 0x10,
[1648065573380] [39479:3699024] CHIP: [IN] 0xf5, 0x7b, 0xfb, 0x6e, 0x3e, 0x65, 0x1e, 0xfe,
[1648065573380] [39479:3699024] CHIP: [SC] Including MRP parameters
[1648065573381] [39479:3699024] CHIP: [IN] Prepared unauthenticated message 0x7f82ae824068 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 34019i with MessageCounter:3015081302.
[1648065573381] [39479:3699024] CHIP: [IN] Sending unauthenticated msg 0x7f82ae824068 with MessageCounter:3015081302 to 0x0000000000000000 at monotonic time: 762938698 msec
[1648065573381] [39479:3699024] CHIP: [SC] Sent Sigma1 msg
[1648065573381] [39479:3699024] CHIP: [CTL] Address resolved for node: 0x0000000000000001
2022-03-23 12:59:33.381 chip-tool-darwin[39479:3699024] OnAddressUpdateComplete. Status ../../third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:555: Success
[1648065573389] [39479:3699024] CHIP: [EM] Received message of type 0x31 with protocolId (0, 0) and MessageCounter:4060609865 on exchange 34019i
[1648065573389] [39479:3699024] CHIP: [EM] Found matching exchange: 34019i, Delegate: 0x7f82ae825038
[1648065573389] [39479:3699024] CHIP: [EM] Rxd Ack; Removing MessageCounter:3015081302 from Retrans Table on exchange 34019i
[1648065573389] [39479:3699024] CHIP: [EM] Removed CHIP MessageCounter:3015081302 from RetransTable on exchange 34019i
[1648065573389] [39479:3699024] CHIP: [SC] Received Sigma2 msg
[1648065573389] [39479:3699024] CHIP: [SC] Peer assigned session session ID 5
[1648065573390] [39479:3699024] CHIP: [SC] The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures.
[1648065573390] [39479:3699024] CHIP: [IN] Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
[1648065573390] [39479:3699024] CHIP: [IN] 0x04, 0x01, 0xba, 0x4f, 0x19, 0xdd, 0x03, 0x5e,
[1648065573390] [39479:3699024] CHIP: [IN] 0x84, 0xdf, 0x6f, 0x0a, 0x07, 0xeb, 0x3a, 0xec,
[1648065573390] [39479:3699024] CHIP: [IN] 0x55, 0xfd, 0xfb, 0x92, 0xc7, 0x53, 0x72, 0x3b,
[1648065573390] [39479:3699024] CHIP: [IN] 0x70, 0x1a, 0xcc, 0x88, 0x72, 0x5c, 0x6a, 0x3a,
[1648065573390] [39479:3699024] CHIP: [IN] 0xb5, 0x02, 0x7e, 0x0c, 0xc5, 0xea, 0x41, 0x8a,
[1648065573390] [39479:3699024] CHIP: [IN] 0x8c, 0x5f, 0x9e, 0x36, 0xae, 0x9c, 0xc7, 0xc8,
[1648065573390] [39479:3699024] CHIP: [IN] 0xd2, 0xf0, 0x1e, 0x89, 0x64, 0xde, 0x19, 0x4f,
[1648065573390] [39479:3699024] CHIP: [IN] 0x07, 0x4e, 0x09, 0x90, 0x25, 0x57, 0xc7, 0x38,
[1648065573390] [39479:3699024] CHIP: [IN] 0x05,
[1648065573390] [39479:3699024] CHIP: [IN] Generated compressed fabric ID
[1648065573390] [39479:3699024] CHIP: [IN] 0xd0, 0x99, 0xe4, 0x0d, 0x93, 0xb1, 0xdc, 0x0c,
[1648065573391] [39479:3699024] CHIP: [SC] Found MRP parameters in the message
[1648065573391] [39479:3699024] CHIP: [SC] Sending Sigma3
[1648065573391] [39479:3699024] CHIP: [EM] Piggybacking Ack for MessageCounter:4060609865 on exchange: 34019i
[1648065573391] [39479:3699024] CHIP: [IN] Prepared unauthenticated message 0x7f82ae824068 to 0x0000000000000000 (0)  of type 0x32 and protocolId (0, 0) on exchange 34019i with MessageCounter:3015081303.
[1648065573391] [39479:3699024] CHIP: [IN] Sending unauthenticated msg 0x7f82ae824068 with MessageCounter:3015081303 to 0x0000000000000000 at monotonic time: 762938708 msec
[1648065573391] [39479:3699024] CHIP: [SC] Sent Sigma3 msg
[1648065573398] [39479:3699024] CHIP: [EM] Received message of type 0x40 with protocolId (0, 0) and MessageCounter:4060609866 on exchange 34019i
[1648065573398] [39479:3699024] CHIP: [EM] Found matching exchange: 34019i, Delegate: 0x7f82ae825038
[1648065573398] [39479:3699024] CHIP: [EM] Rxd Ack; Removing MessageCounter:3015081303 from Retrans Table on exchange 34019i
[1648065573398] [39479:3699024] CHIP: [EM] Removed CHIP MessageCounter:3015081303 from RetransTable on exchange 34019i
[1648065573398] [39479:3699024] CHIP: [SC] Success status report received. Session was established
[1648065573398] [39479:3699024] CHIP: [IN] New secure session created for device 0x0000000000000001, LSID:1 PSID:5!
2022-03-23 12:59:33.398 chip-tool-darwin[39479:3699024] DevicePairingDelegate Pairing complete. Status ../../third_party/connectedhomeip/src/controller/CHIPDeviceController.cpp:1478: Success
[1648065573398] [39479:3699025] CHIP: [TOO] Sending cluster (0x00000201) ReportAttribute (0x0000FFFD) on endpoint 1
[1648065573398] [39479:3699024] CHIP: [EM] Sending Standalone Ack for MessageCounter:4060609866 on exchange 34019i
[1648065573398] [39479:3699024] CHIP: [IN] Prepared unauthenticated message 0x70000759e520 to 0x0000000000000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 34019i with MessageCounter:3015081304.
[1648065573398] [39479:3699024] CHIP: [IN] Sending unauthenticated msg 0x70000759e520 with MessageCounter:3015081304 to 0x0000000000000000 at monotonic time: 762938716 msec
[1648065573398] [39479:3699024] CHIP: [EM] Flushed pending ack for MessageCounter:4060609866 on exchange 34019i
[1648065573399] [39479:3699025] CHIP: [CTL] Response Time: PFvPvtE+3161665782
[1648065573399] [39479:3699025] CHIP: [IN] Prepared secure message 0x7f82ae824068 to 0x0000000000000001 (1)  of type 0x3 and protocolId (0, 1) on exchange 34020i with MessageCounter:12034380.
[1648065573400] [39479:3699025] CHIP: [IN] Sending encrypted msg 0x7f82ae824068 with MessageCounter:12034380 to 0x0000000000000001 (1) at monotonic time: 762938717 msec
[1648065573400] [39479:3699025] CHIP: [DMG] MoveToState ReadClient[0x7f82b0105a30]: Moving to [AwaitingIn]
[1648065573400] [39479:3699025] CHIP: [TOO] Error: ../../third_party/connectedhomeip/zzz_generated/chip-tool-darwin/zap-generated/cluster/Commands.h:59990: Success
[1648065573404] [39479:3699025] CHIP: [EM] Received message of type 0x5 with protocolId (0, 1) and MessageCounter:9152681 on exchange 34020i
[1648065573404] [39479:3699025] CHIP: [EM] Found matching exchange: 34020i, Delegate: 0x7f82b0105a30
[1648065573404] [39479:3699025] CHIP: [EM] Rxd Ack; Removing MessageCounter:12034380 from Retrans Table on exchange 34020i
[1648065573404] [39479:3699025] CHIP: [EM] Removed CHIP MessageCounter:12034380 from RetransTable on exchange 34020i
[1648065573404] [39479:3699025] CHIP: [DMG] ReportDataMessage =
[1648065573404] [39479:3699025] CHIP: [DMG] {
[1648065573404] [39479:3699025] CHIP: [DMG] 	SubscriptionId = 0xc9b9a0d4b1de3e72,
[1648065573404] [39479:3699025] CHIP: [DMG] 	AttributeReportIBs =
[1648065573404] [39479:3699025] CHIP: [DMG] 	[
[1648065573404] [39479:3699025] CHIP: [DMG] 		AttributeReportIB =
[1648065573404] [39479:3699025] CHIP: [DMG] 		{
[1648065573404] [39479:3699025] CHIP: [DMG] 			AttributeDataIB =
[1648065573404] [39479:3699025] CHIP: [DMG] 			{
[1648065573404] [39479:3699025] CHIP: [DMG] 				DataVersion = 0x48c77a15,
[1648065573404] [39479:3699025] CHIP: [DMG] 				AttributePathIB =
[1648065573404] [39479:3699025] CHIP: [DMG] 				{
[1648065573404] [39479:3699025] CHIP: [DMG] 					Endpoint = 0x1,
[1648065573404] [39479:3699025] CHIP: [DMG] 					Cluster = 0x201,
[1648065573404] [39479:3699025] CHIP: [DMG] 					Attribute = 0x0000_FFFD,
[1648065573404] [39479:3699025] CHIP: [DMG] 				}
[1648065573404] [39479:3699025] CHIP: [DMG]
[1648065573404] [39479:3699025] CHIP: [DMG] 					Data = 3,
[1648065573404] [39479:3699025] CHIP: [DMG] 			},
[1648065573404] [39479:3699025] CHIP: [DMG]
[1648065573404] [39479:3699025] CHIP: [DMG] 		},
[1648065573404] [39479:3699025] CHIP: [DMG]
[1648065573404] [39479:3699025] CHIP: [DMG] 	],
[1648065573404] [39479:3699025] CHIP: [DMG]
[1648065573404] [39479:3699025] CHIP: [DMG] 	InteractionModelRevision = 1
[1648065573404] [39479:3699025] CHIP: [DMG] }
[1648065573404] [39479:3699025] CHIP: [DMG] MoveToState ReadClient[0x7f82b0105a30]: Moving to [AwaitingSu]
[1648065573404] [39479:3699024] CHIP: [CTL] Response Time: PFvPvtE+3161665782 0.005383 seconds
[1648065573404] [39479:3699025] CHIP: [EM] Piggybacking Ack for MessageCounter:9152681 on exchange: 34020i
[1648065573404] [39479:3699025] CHIP: [IN] Prepared secure message 0x7f82ae824068 to 0x0000000000000001 (1)  of type 0x1 and protocolId (0, 1) on exchange 34020i with MessageCounter:12034381.
[1648065573404] [39479:3699025] CHIP: [IN] Sending encrypted msg 0x7f82ae824068 with MessageCounter:12034381 to 0x0000000000000001 (1) at monotonic time: 762938722 msec
2022-03-23 12:59:33.404 chip-tool-darwin[39479:3699024] Thermostat.ClusterRevision response 3
[1648065573404] [39479:3699024] CHIP: [TOO] Shutting down controller
[1648065573405] [39479:3699025] CHIP: [CTL] Shutting down the commissioner
[1648065573405] [39479:3699025] CHIP: [CTL] Shutting down the controller
[1648065573405] [39479:3699025] CHIP: [CTL] Shutting down the System State, this will teardown the CHIP Stack
[1648065573405] [39479:3699025] CHIP: [DMG] IM WH moving to [Uninitialized]
[1648065573405] [39479:3699025] CHIP: [DMG] IM WH moving to [Uninitialized]
[1648065573405] [39479:3699025] CHIP: [DMG] IM WH moving to [Uninitialized]
[1648065573405] [39479:3699025] CHIP: [DMG] IM WH moving to [Uninitialized]
[1648065573405] [39479:3699025] CHIP: [BLE] CancelConnection
[1648065573405] [39479:3699025] CHIP: [DL] Inet Layer shutdown
[1648065573405] [39479:3699025] CHIP: [DL] BLE shutdown
[1648065573405] [39479:3699025] CHIP: [DL] System Layer shutdown
[1648065573405] [39479:3699025] CHIP: [SPT] VerifyOrDie failure at ../../third_party/connectedhomeip/src/lib/support/Pool.h:217: Allocated() == 0
zsh: abort      ./chip-tool-darwin thermostat subscribe cluster-revision 1 10 1 1 1
Accessory side log:
[1648065547.288293][1860:1860] CHIP:DMG: Unblock report hold after min 1 seconds
[1648065547.290528][1860:1860] CHIP:EM: Failed to Send CHIP MessageCounter:12838430 on exchange 23780r sendCount: 3 max retries: 3
[1648065551.287095][1860:1860] CHIP:EM: Retransmitting MessageCounter:12838431 on exchange 46897i Send Cnt 0
[1648065551.287188][1860:1860] CHIP:IN: Sending encrypted msg 0xaaaaca020588 with MessageCounter:12838431 to 0x3008E2353A83BE1A (1) at monotonic time: 202502 msec
[1648065552.562741][1860:1860] CHIP:DIS: Broadcasting mDns reply for query from 192.168.1.104
[1648065552.565210][1860:1860] CHIP:DIS: Broadcasting mDns reply for query from 192.168.1.104
[1648065553.287559][1860:1860] CHIP:EM: Retransmitting MessageCounter:12838431 on exchange 46897i Send Cnt 1
[1648065553.287648][1860:1860] CHIP:IN: Sending encrypted msg 0xaaaaca020588 with MessageCounter:12838431 to 0x3008E2353A83BE1A (1) at monotonic time: 204503 msec
[1648065555.290018][1860:1860] CHIP:EM: Retransmitting MessageCounter:12838431 on exchange 46897i Send Cnt 2
[1648065555.290104][1860:1860] CHIP:IN: Sending encrypted msg 0xaaaaca020588 with MessageCounter:12838431 to 0x3008E2353A83BE1A (1) at monotonic time: 206505 msec
[1648065556.289426][1860:1860] CHIP:DMG: Refresh subscribe timer sync after 9 seconds
[1648065557.290707][1860:1860] CHIP:EM: Failed to Send CHIP MessageCounter:12838431 on exchange 46897i sendCount: 3 max retries: 3
[1648065558.288037][1860:1860] CHIP:DMG: Time out! failed to receive status response from Exchange: 46897i
[1648065558.288101][1860:1860] CHIP:DMG:  OnReportConfirm: NumReports = 0
[1648065558.288143][1860:1860] CHIP:DMG: IM RH moving to [AwaitingDestruction]
[1648065562.175250][1860:1860] CHIP:DIS: Broadcasting mDns reply for query from 192.168.1.104
[1648065562.177674][1860:1860] CHIP:DIS: Broadcasting mDns reply for query from 192.168.1.104
[1648065565.185519][1860:1860] CHIP:DIS: Broadcasting mDns reply for query from 192.168.1.104
[1648065565.187802][1860:1860] CHIP:DIS: Broadcasting mDns reply for query from 192.168.1.104
[1648065573.515628][1860:1860] CHIP:EM: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:3015081302 on exchange 34019r
[1648065573.515734][1860:1860] CHIP:EM: Handling via exchange: 34019r, Delegate: 0xaaaaca01ff88
[1648065573.515817][1860:1860] CHIP:IN: CASE Server received Sigma1 message. Starting handshake. EC 0xaaaaca0208a0
[1648065573.515874][1860:1860] CHIP:DIS: CASE handshake initiated, closing all BLE Connections
[1648065573.515932][1860:1860] CHIP:SC: Waiting for Sigma1 msg
[1648065573.515979][1860:1860] CHIP:IN: CASE Server disabling CASE session setups
[1648065573.516035][1860:1860] CHIP:SC: Received Sigma1 msg
[1648065573.516129][1860:1860] CHIP:SC: Found MRP parameters in the message
[1648065573.516191][1860:1860] CHIP:SC: Peer assigned session key ID 1
[1648065573.516242][1860:1860] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1648065573.516291][1860:1860] CHIP:ZCL: OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000001, VendorId 0x0000
[1648065573.516343][1860:1860] CHIP:ZCL: OpCreds: Call to fabricListChanged
[1648065573.516395][1860:1860] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 8ae8889d
[1648065573.516460][1860:1860] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 8ae8889e
[1648065573.516567][1860:1860] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1648065573.516776][1860:1860] CHIP:IN: Generating DestinationID. Fabric ID 0x0000000000000000, Dest node ID 0x0000000000000001, Random data
[1648065573.516845][1860:1860] CHIP:IN: 0x56, 0xd5, 0x7c, 0x2a, 0xe0, 0x87, 0x44, 0xe5,
[1648065573.516898][1860:1860] CHIP:IN: 0xff, 0xb5, 0x1a, 0x4a, 0xb0, 0xd9, 0xf2, 0x1b,
[1648065573.516951][1860:1860] CHIP:IN: 0xf4, 0x37, 0xd8, 0x85, 0xf5, 0x05, 0xbd, 0x4c,
[1648065573.517001][1860:1860] CHIP:IN: 0x3c, 0x68, 0xa9, 0xe9, 0xc4, 0x32, 0x24, 0x83,
[1648065573.517045][1860:1860] CHIP:IN: Root pubkey
[1648065573.517097][1860:1860] CHIP:IN: 0x04, 0x01, 0xba, 0x4f, 0x19, 0xdd, 0x03, 0x5e,
[1648065573.517148][1860:1860] CHIP:IN: 0x84, 0xdf, 0x6f, 0x0a, 0x07, 0xeb, 0x3a, 0xec,
[1648065573.517199][1860:1860] CHIP:IN: 0x55, 0xfd, 0xfb, 0x92, 0xc7, 0x53, 0x72, 0x3b,
[1648065573.517249][1860:1860] CHIP:IN: 0x70, 0x1a, 0xcc, 0x88, 0x72, 0x5c, 0x6a, 0x3a,
[1648065573.517300][1860:1860] CHIP:IN: 0xb5, 0x02, 0x7e, 0x0c, 0xc5, 0xea, 0x41, 0x8a,
[1648065573.517349][1860:1860] CHIP:IN: 0x8c, 0x5f, 0x9e, 0x36, 0xae, 0x9c, 0xc7, 0xc8,
[1648065573.517399][1860:1860] CHIP:IN: 0xd2, 0xf0, 0x1e, 0x89, 0x64, 0xde, 0x19, 0x4f,
[1648065573.517449][1860:1860] CHIP:IN: 0x07, 0x4e, 0x09, 0x90, 0x25, 0x57, 0xc7, 0x38,
[1648065573.517494][1860:1860] CHIP:IN: 0x05,
[1648065573.517538][1860:1860] CHIP:IN: IPK
[1648065573.517589][1860:1860] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
[1648065573.517640][1860:1860] CHIP:IN: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
[1648065573.517717][1860:1860] CHIP:IN: Generated DestinationID output
[1648065573.517773][1860:1860] CHIP:IN: 0x04, 0xe1, 0x08, 0xa2, 0x15, 0xf6, 0x00, 0x4b,
[1648065573.517824][1860:1860] CHIP:IN: 0x7e, 0x7c, 0x09, 0xd5, 0xfd, 0x54, 0xd1, 0x72,
[1648065573.517875][1860:1860] CHIP:IN: 0xed, 0x84, 0x36, 0x58, 0x05, 0x14, 0x3a, 0x10,
[1648065573.517924][1860:1860] CHIP:IN: 0xf5, 0x7b, 0xfb, 0x6e, 0x3e, 0x65, 0x1e, 0xfe,
[1648065573.517970][1860:1860] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1648065573.518016][1860:1860] CHIP:ZCL: OpCreds: Fabric 0x1 was retrieved from storage. FabricId 0x0000000000000000, NodeId 0x0000000000000001, VendorId 0x0000
[1648065573.518059][1860:1860] CHIP:ZCL: OpCreds: Call to fabricListChanged
[1648065573.518096][1860:1860] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 8ae8889f
[1648065573.518139][1860:1860] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 8ae888a0
[1648065573.518188][1860:1860] CHIP:DIS: Fabric (1) loaded from storage. Calling OnFabricRetrievedFromStorage
[1648065573.520687][1860:1860] CHIP:SC: Including MRP parameters
[1648065573.520806][1860:1860] CHIP:EM: Piggybacking Ack for MessageCounter:3015081302 on exchange: 34019r
[1648065573.520883][1860:1860] CHIP:IN: Prepared unauthenticated message 0xaaaaca020568 to 0x0000000000000000 (0)  of type 0x31 and protocolId (0, 0) on exchange 34019r with MessageCounter:4060609865.
[1648065573.520963][1860:1860] CHIP:IN: Sending unauthenticated msg 0xaaaaca020568 with MessageCounter:4060609865 to 0x0000000000000000 at monotonic time: 224736 msec
[1648065573.521169][1860:1860] CHIP:SC: Sent Sigma2 msg
[1648065573.524997][1860:1860] CHIP:EM: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:3015081303 on exchange 34019r
[1648065573.525064][1860:1860] CHIP:EM: Found matching exchange: 34019r, Delegate: 0xaaaaca01ff98
[1648065573.525142][1860:1860] CHIP:EM: Rxd Ack; Removing MessageCounter:4060609865 from Retrans Table on exchange 34019r
[1648065573.525196][1860:1860] CHIP:EM: Removed CHIP MessageCounter:4060609865 from RetransTable on exchange 34019r
[1648065573.525267][1860:1860] CHIP:SC: Received Sigma3 msg
[1648065573.525470][1860:1860] CHIP:SC: The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures.
[1648065573.527753][1860:1860] CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000000 and root pubkey
[1648065573.527794][1860:1860] CHIP:IN: 0x04, 0x01, 0xba, 0x4f, 0x19, 0xdd, 0x03, 0x5e,
[1648065573.527821][1860:1860] CHIP:IN: 0x84, 0xdf, 0x6f, 0x0a, 0x07, 0xeb, 0x3a, 0xec,
[1648065573.527848][1860:1860] CHIP:IN: 0x55, 0xfd, 0xfb, 0x92, 0xc7, 0x53, 0x72, 0x3b,
[1648065573.527873][1860:1860] CHIP:IN: 0x70, 0x1a, 0xcc, 0x88, 0x72, 0x5c, 0x6a, 0x3a,
[1648065573.527898][1860:1860] CHIP:IN: 0xb5, 0x02, 0x7e, 0x0c, 0xc5, 0xea, 0x41, 0x8a,
[1648065573.527923][1860:1860] CHIP:IN: 0x8c, 0x5f, 0x9e, 0x36, 0xae, 0x9c, 0xc7, 0xc8,
[1648065573.527948][1860:1860] CHIP:IN: 0xd2, 0xf0, 0x1e, 0x89, 0x64, 0xde, 0x19, 0x4f,
[1648065573.527973][1860:1860] CHIP:IN: 0x07, 0x4e, 0x09, 0x90, 0x25, 0x57, 0xc7, 0x38,
[1648065573.527995][1860:1860] CHIP:IN: 0x05,
[1648065573.528049][1860:1860] CHIP:IN: Generated compressed fabric ID
[1648065573.528078][1860:1860] CHIP:IN: 0xd0, 0x99, 0xe4, 0x0d, 0x93, 0xb1, 0xdc, 0x0c,
[1648065573.529126][1860:1860] CHIP:SC: Sending status report. Protocol code 0, exchange 34019
[1648065573.529173][1860:1860] CHIP:EM: Piggybacking Ack for MessageCounter:3015081303 on exchange: 34019r
[1648065573.529212][1860:1860] CHIP:IN: Prepared unauthenticated message 0xaaaaca020568 to 0x0000000000000000 (0)  of type 0x40 and protocolId (0, 0) on exchange 34019r with MessageCounter:4060609866.
[1648065573.529253][1860:1860] CHIP:IN: Sending unauthenticated msg 0xaaaaca020568 with MessageCounter:4060609866 to 0x0000000000000000 at monotonic time: 224744 msec
[1648065573.529373][1860:1860] CHIP:IN: CASE Session established. Setting up the secure channel.
[1648065573.529413][1860:1860] CHIP:IN: New secure session created for device 0x3008E2353A83BE1A, LSID:5 PSID:1!
[1648065573.529526][1860:1860] CHIP:IN: CASE secure channel is available now.
[1648065573.529553][1860:1860] CHIP:IN: CASE Server enabling CASE session setups
[1648065573.532954][1860:1860] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:3015081304 on exchange 34019r
[1648065573.532988][1860:1860] CHIP:EM: Found matching exchange: 34019r, Delegate: (nil)
[1648065573.533028][1860:1860] CHIP:EM: Rxd Ack; Removing MessageCounter:4060609866 from Retrans Table on exchange 34019r
[1648065573.533054][1860:1860] CHIP:EM: Removed CHIP MessageCounter:4060609866 from RetransTable on exchange 34019r
[1648065573.533529][1860:1860] CHIP:EM: Received message of type 0x3 with protocolId (0, 1) and MessageCounter:12034380 on exchange 34020r
[1648065573.533567][1860:1860] CHIP:EM: Handling via exchange: 34020r, Delegate: 0xaaaaca01ae28
[1648065573.533604][1860:1860] CHIP:IM: Received Subscribe request
[1648065573.533675][1860:1860] CHIP:DMG: SubscribeRequestMessage =
[1648065573.533704][1860:1860] CHIP:DMG: {
[1648065573.533731][1860:1860] CHIP:DMG: 	KeepSubscriptions = false,
[1648065573.533760][1860:1860] CHIP:DMG: 	MinIntervalFloorSeconds = 0x1,
[1648065573.533792][1860:1860] CHIP:DMG: 	MaxIntervalCeilingSeconds = 0xa,
[1648065573.533819][1860:1860] CHIP:DMG: 	AttributePathIBs =
[1648065573.533849][1860:1860] CHIP:DMG: 	[
[1648065573.533876][1860:1860] CHIP:DMG: 		AttributePathIB =
[1648065573.533909][1860:1860] CHIP:DMG: 		{
[1648065573.533942][1860:1860] CHIP:DMG: 			Endpoint = 0x1,
[1648065573.533979][1860:1860] CHIP:DMG: 			Cluster = 0x201,
[1648065573.534016][1860:1860] CHIP:DMG: 			Attribute = 0x0000_FFFD,
[1648065573.534049][1860:1860] CHIP:DMG: 		}
[1648065573.534084][1860:1860] CHIP:DMG:
[1648065573.534114][1860:1860] CHIP:DMG: 	],
[1648065573.534146][1860:1860] CHIP:DMG:
[1648065573.534175][1860:1860] CHIP:DMG: 	isFabricFiltered = true,
[1648065573.534203][1860:1860] CHIP:DMG: 	InteractionModelRevision = 1
[1648065573.534229][1860:1860] CHIP:DMG: },
[1648065573.534355][1860:1860] CHIP:DMG: IM RH moving to [GeneratingReports]
[1648065573.534444][1860:1860] CHIP:DMG: RE:Run Cluster 201, Attribute fffd is dirty
[1648065573.534473][1860:1860] CHIP:DMG: Reading attribute: Cluster=0x0000_0201 Endpoint=1 AttributeId=0x0000_FFFD (expanded=0)
[1648065573.534507][1860:1860] CHIP:DMG: AccessControl: checking f=1 a=c s=0x3008E2353A83BE1A t= c=0x0000_0201 e=1 p=v
[1648065573.534624][1860:1860] CHIP:DMG:  Sending report (payload has 46 bytes)...
[1648065573.534654][1860:1860] CHIP:DMG: IM RH moving to [AwaitingReportResponse]
[1648065573.534685][1860:1860] CHIP:EM: Piggybacking Ack for MessageCounter:12034380 on exchange: 34020r
[1648065573.534742][1860:1860] CHIP:IN: Prepared secure message 0xaaaaca020568 to 0x3008E2353A83BE1A (1)  of type 0x5 and protocolId (0, 1) on exchange 34020r with MessageCounter:9152681.
[1648065573.534783][1860:1860] CHIP:IN: Sending encrypted msg 0xaaaaca020568 with MessageCounter:9152681 to 0x3008E2353A83BE1A (1) at monotonic time: 224750 msec
[1648065573.534885][1860:1860] CHIP:DMG:  ReportsInFlight = 1 with readHandler 0, RE has no more messages
[1648065573.545037][1860:1860] CHIP:EM: Received message of type 0x1 with protocolId (0, 1) and MessageCounter:12034381 on exchange 34020r
[1648065573.545072][1860:1860] CHIP:EM: Found matching exchange: 34020r, Delegate: 0xaaaad2990700
[1648065573.545111][1860:1860] CHIP:EM: Rxd Ack; Removing MessageCounter:9152681 from Retrans Table on exchange 34020r
[1648065573.545137][1860:1860] CHIP:EM: Removed CHIP MessageCounter:9152681 from RetransTable on exchange 34020r
[1648065573.545188][1860:1860] CHIP:DMG: StatusResponseMessage =
[1648065573.545217][1860:1860] CHIP:DMG: {
[1648065573.545243][1860:1860] CHIP:DMG: 	Status = 0x0,
[1648065573.545272][1860:1860] CHIP:DMG: 	InteractionModelRevision = 1
[1648065573.545298][1860:1860] CHIP:DMG: }
[1648065573.545325][1860:1860] CHIP:IM: Received status response, status is 0
[1648065573.545365][1860:1860] CHIP:DMG: Refresh Subscribe Sync Timer with max 10 seconds
[1648065573.545397][1860:1860] CHIP:DMG:  OnReportConfirm: NumReports = 0
[1648065573.545421][1860:1860] CHIP:DMG: IM RH moving to [GeneratingReports]

@Garik098 I don't see those responses in chip tool see log below:
[1649281321240] [65075:6225227] CHIP: [EM] Received message of type 0x5 with protocolId (0, 1) and MessageCounter:1189803 on exchange 57810i
[1649281321240] [65075:6225227] CHIP: [EM] Found matching exchange: 57810i, Delegate: 0x6000000a40f0
[1649281321240] [65075:6225227] CHIP: [EM] Rxd Ack; Removing MessageCounter:5804149 from Retrans Table on exchange 57810i
[1649281321240] [65075:6225227] CHIP: [EM] Removed CHIP MessageCounter:5804149 from RetransTable on exchange 57810i
[1649281321240] [65075:6225227] CHIP: [DMG] ReportDataMessage =
[1649281321240] [65075:6225227] CHIP: [DMG] {
[1649281321240] [65075:6225227] CHIP: [DMG] 	SubscriptionId = 0xd5a3da6b6165b35a,
[1649281321240] [65075:6225227] CHIP: [DMG] 	AttributeReportIBs =
[1649281321240] [65075:6225227] CHIP: [DMG] 	[
[1649281321240] [65075:6225227] CHIP: [DMG] 		AttributeReportIB =
[1649281321240] [65075:6225227] CHIP: [DMG] 		{
[1649281321240] [65075:6225227] CHIP: [DMG] 			AttributeDataIB =
[1649281321240] [65075:6225227] CHIP: [DMG] 			{
[1649281321240] [65075:6225227] CHIP: [DMG] 				DataVersion = 0x365579c0,
[1649281321240] [65075:6225227] CHIP: [DMG] 				AttributePathIB =
[1649281321240] [65075:6225227] CHIP: [DMG] 				{
[1649281321240] [65075:6225227] CHIP: [DMG] 					Endpoint = 0x1,
[1649281321240] [65075:6225227] CHIP: [DMG] 					Cluster = 0x201,
[1649281321240] [65075:6225227] CHIP: [DMG] 					Attribute = 0x0000_FFFD,
[1649281321240] [65075:6225227] CHIP: [DMG] 				}
[1649281321240] [65075:6225227] CHIP: [DMG]
[1649281321240] [65075:6225227] CHIP: [DMG] 					Data = 3,
[1649281321240] [65075:6225227] CHIP: [DMG] 			},
[1649281321240] [65075:6225227] CHIP: [DMG]
[1649281321240] [65075:6225227] CHIP: [DMG] 		},
[1649281321240] [65075:6225227] CHIP: [DMG]
[1649281321240] [65075:6225227] CHIP: [DMG] 	],
[1649281321240] [65075:6225227] CHIP: [DMG]
[1649281321240] [65075:6225227] CHIP: [DMG] 	InteractionModelRevision = 1
[1649281321240] [65075:6225227] CHIP: [DMG] }
[1649281321241] [65075:6225227] CHIP: [TOO] Endpoint: 1 Cluster: 0x0000_0201 Attribute 0x0000_FFFD DataVersion: 911571392
[1649281321242] [65075:6225227] CHIP: [TOO]   ClusterRevision: 3

After discussion on getting more clarity on the test step and the way to perform it, closing this ticket and opening new ticket https://github.com/project-chip/connectedhomeip/issues/17151

repo: project-chip/connectedhomeip


text:
Reject subscription establishment if subscriber has no access

Problem
See this spec issue.
Proposed Solution
Iterate over every expanded path in the SubscribeRequest and check if any of the paths have at least View privilege (this is already handled by calling RequiredPrivilege::ForReadAttribute(aPath)). If not a single path has that privilege, the subscription should not be established.
This processing should happen BEFORE we allocate a ReadHandler to serve the subscription. This ensures we don't tear down existing valid subscriptions to serve a subscription that is not valid.

Cert Blocker Review: @CamWms @bzbarsky-apple @mrjerryjohns - Can we confirm if the current spec, SDK, and test plans are currently in sync. If so, we should move this to post 1.0.

V1 reivew: PR existed, needs reviving. Since this is a spec issue, it will be accepted in 1.0

@yunhanw-google to resurrect the PR that I had open previously, and ensure the relevant changes are made to that PR to ensure it is spec compliant.

source: gharchive/issue

authors: andy31415 mrjerryjohns woody-apple

license_type: permissive

license_source: github-api