From 6eb6869b2ea4a01c905d906c3ddc67baa9ca5c55 Mon Sep 17 00:00:00 2001 From: Jeff Tung <100387939+jtung-apple@users.noreply.github.com> Date: Wed, 13 Mar 2024 07:58:23 -0700 Subject: [PATCH 1/6] [Darwin] MTRDevice attribute storage mutable array enumeration fix --- .../CHIP/MTRDeviceControllerDataStore.mm | 193 ++++++++++++------ 1 file changed, 136 insertions(+), 57 deletions(-) diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm index 0495211b76b449..08b537df784577 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm @@ -329,12 +329,12 @@ - (BOOL)_storeAttributeCacheValue:(id)value forKey:(NSString *)key sharingType:MTRStorageSharingTypeNotShared]; } -- (void)_removeAttributeCacheValueForKey:(NSString *)key +- (BOOL)_removeAttributeCacheValueForKey:(NSString *)key { - [_storageDelegate controller:_controller - removeValueForKey:key - securityLevel:MTRStorageSecurityLevelSecure - sharingType:MTRStorageSharingTypeNotShared]; + return [_storageDelegate controller:_controller + removeValueForKey:key + securityLevel:MTRStorageSecurityLevelSecure + sharingType:MTRStorageSharingTypeNotShared]; } static NSString * sAttributeCacheNodeIndexKey = @"attrCacheNodeIndex"; @@ -349,9 +349,9 @@ - (BOOL)_storeNodeIndex:(NSArray *)nodeIndex return [self _storeAttributeCacheValue:nodeIndex forKey:sAttributeCacheNodeIndexKey]; } -- (void)_deleteNodeIndex +- (BOOL)_deleteNodeIndex { - [self _removeAttributeCacheValueForKey:sAttributeCacheNodeIndexKey]; + return [self _removeAttributeCacheValueForKey:sAttributeCacheNodeIndexKey]; } static NSString * sAttributeCacheEndpointIndexKeyPrefix = @"attrCacheEndpointIndex"; @@ -371,9 +371,9 @@ - (BOOL)_storeEndpointIndex:(NSArray *)endpointIndex forNodeID:(NSNu return [self _storeAttributeCacheValue:endpointIndex forKey:[self _endpointIndexKeyForNodeID:nodeID]]; } -- (void)_deleteEndpointIndexForNodeID:(NSNumber *)nodeID +- (BOOL)_deleteEndpointIndexForNodeID:(NSNumber *)nodeID { - [self _removeAttributeCacheValueForKey:[self _endpointIndexKeyForNodeID:nodeID]]; + return [self _removeAttributeCacheValueForKey:[self _endpointIndexKeyForNodeID:nodeID]]; } static NSString * sAttributeCacheClusterIndexKeyPrefix = @"attrCacheClusterIndex"; @@ -393,9 +393,9 @@ - (BOOL)_storeClusterIndex:(NSArray *)clusterIndex forNodeID:(NSNumb return [self _storeAttributeCacheValue:clusterIndex forKey:[self _clusterIndexKeyForNodeID:nodeID endpointID:endpointID]]; } -- (void)_deleteClusterIndexForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID +- (BOOL)_deleteClusterIndexForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID { - [self _removeAttributeCacheValueForKey:[self _clusterIndexKeyForNodeID:nodeID endpointID:endpointID]]; + return [self _removeAttributeCacheValueForKey:[self _clusterIndexKeyForNodeID:nodeID endpointID:endpointID]]; } static NSString * sAttributeCacheAttributeIndexKeyPrefix = @"attrCacheAttributeIndex"; @@ -415,9 +415,9 @@ - (BOOL)_storeAttributeIndex:(NSArray *)attributeIndex forNodeID:(NS return [self _storeAttributeCacheValue:attributeIndex forKey:[self _attributeIndexKeyForNodeID:nodeID endpointID:endpointID clusterID:clusterID]]; } -- (void)_deleteAttributeIndexForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID clusterID:(NSNumber *)clusterID +- (BOOL)_deleteAttributeIndexForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID clusterID:(NSNumber *)clusterID { - [self _removeAttributeCacheValueForKey:[self _attributeIndexKeyForNodeID:nodeID endpointID:endpointID clusterID:clusterID]]; + return [self _removeAttributeCacheValueForKey:[self _attributeIndexKeyForNodeID:nodeID endpointID:endpointID clusterID:clusterID]]; } static NSString * sAttributeCacheAttributeValueKeyPrefix = @"attrCacheAttributeValue"; @@ -437,13 +437,17 @@ - (BOOL)_storeAttributeValue:(NSDictionary *)value forNodeID:(NSNumber *)nodeID return [self _storeAttributeCacheValue:value forKey:[self _attributeValueKeyForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]]; } -- (void)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID clusterID:(NSNumber *)clusterID attributeID:(NSNumber *)attributeID +- (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID clusterID:(NSNumber *)clusterID attributeID:(NSNumber *)attributeID { - [self _removeAttributeCacheValueForKey:[self _attributeValueKeyForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]]; + return [self _removeAttributeCacheValueForKey:[self _attributeValueKeyForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]]; } #pragma - Attribute Cache management +#ifndef ATTRIBUTE_CACHE_VERBOSE_LOGGING +#define ATTRIBUTE_CACHE_VERBOSE_LOGGING 0 +#endif + - (nullable NSArray *)getStoredAttributesForNodeID:(NSNumber *)nodeID { __block NSMutableArray * attributesToReturn = nil; @@ -451,6 +455,10 @@ - (void)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * // Fetch node index NSArray * nodeIndex = [self _fetchNodeIndex]; +#if ATTRIBUTE_CACHE_VERBOSE_LOGGING + MTR_LOG_INFO("Fetch got %lu values for nodeIndex", static_cast(nodeIndex.count)); +#endif + if (![nodeIndex containsObject:nodeID]) { // Sanity check and delete if nodeID exists in index NSArray * endpointIndex = [self _fetchEndpointIndexForNodeID:nodeID]; @@ -458,6 +466,8 @@ - (void)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * MTR_LOG_ERROR("Persistent attribute cache contains orphaned entry for nodeID %@ - deleting", nodeID); [self clearStoredAttributesForNodeID:nodeID]; } + + MTR_LOG_INFO("Fetch got no value for endpointIndex @ 0x%016llX", nodeID.unsignedLongLongValue); attributesToReturn = nil; return; } @@ -465,17 +475,33 @@ - (void)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * // Fetch endpoint index NSArray * endpointIndex = [self _fetchEndpointIndexForNodeID:nodeID]; +#if ATTRIBUTE_CACHE_VERBOSE_LOGGING + MTR_LOG_INFO("Fetch got %lu values for endpointIndex @ 0x%016llX", static_cast(endpointIndex.count), nodeID.unsignedLongLongValue); +#endif + for (NSNumber * endpointID in endpointIndex) { // Fetch endpoint index NSArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID]; +#if ATTRIBUTE_CACHE_VERBOSE_LOGGING + MTR_LOG_INFO("Fetch got %lu values for clusterIndex @ 0x%016llX:0x%04X", static_cast(clusterIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); +#endif + for (NSNumber * clusterID in clusterIndex) { // Fetch endpoint index NSArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; +#if ATTRIBUTE_CACHE_VERBOSE_LOGGING + MTR_LOG_INFO("Fetch got %lu values for attributeIndex @ 0x%016llX:0x%04X:0x%08lX", static_cast(attributeIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); +#endif + for (NSNumber * attributeID in attributeIndex) { NSDictionary * value = [self _fetchAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; +#if ATTRIBUTE_CACHE_VERBOSE_LOGGING + MTR_LOG_INFO("Fetch got %u values for attribute value @ 0x%016llX:0x%04X:0x%08lX:0x%08lX", value ? 1 : 0, nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); +#endif + if (value) { if (!attributesToReturn) { attributesToReturn = [NSMutableArray array]; @@ -499,79 +525,95 @@ - (void)_pruneEmptyStoredAttributesBranches { dispatch_assert_queue(_storageDelegateQueue); + NSUInteger storeFailures = 0; + // Fetch node index - NSMutableArray * nodeIndex = [self _fetchNodeIndex].mutableCopy; - NSUInteger nodeIndexCount = nodeIndex.count; + NSArray * nodeIndex = [self _fetchNodeIndex].mutableCopy; + NSMutableArray * nodeIndexCopy = nodeIndex.mutableCopy; - NSUInteger storeFailures = 0; for (NSNumber * nodeID in nodeIndex) { // Fetch endpoint index - NSMutableArray * endpointIndex = [self _fetchEndpointIndexForNodeID:nodeID].mutableCopy; - NSUInteger endpointIndexCount = endpointIndex.count; + NSArray * endpointIndex = [self _fetchEndpointIndexForNodeID:nodeID]; + NSMutableArray * endpointIndexCopy = endpointIndex.mutableCopy; for (NSNumber * endpointID in endpointIndex) { // Fetch endpoint index - NSMutableArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID].mutableCopy; - NSUInteger clusterIndexCount = clusterIndex.count; + NSArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID].mutableCopy; + NSMutableArray * clusterIndexCopy = clusterIndex.mutableCopy; for (NSNumber * clusterID in clusterIndex) { // Fetch endpoint index - NSMutableArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID].mutableCopy; - NSUInteger attributeIndexCount = attributeIndex.count; + NSArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID].mutableCopy; + NSMutableArray * attributeIndexCopy = attributeIndex.mutableCopy; for (NSNumber * attributeID in attributeIndex) { NSDictionary * value = [self _fetchAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; if (!value) { - [attributeIndex removeObject:attributeID]; + [attributeIndexCopy removeObject:attributeID]; } } - if (!attributeIndex.count) { - [clusterIndex removeObject:clusterID]; - } else if (attributeIndex.count != attributeIndexCount) { - BOOL success = [self _storeAttributeIndex:attributeIndex forNodeID:nodeID endpointID:endpointID clusterID:clusterID]; + if (attributeIndex.count != attributeIndexCopy.count) { + BOOL success; if (!success) { + if (attributeIndexCopy.count) { + success = [self _storeAttributeIndex:attributeIndexCopy forNodeID:nodeID endpointID:endpointID clusterID:clusterID]; + } else { + [clusterIndexCopy removeObject:clusterID]; + success = [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; + } storeFailures++; - MTR_LOG_INFO("Store failed for attributeIndex"); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for attributeIndex @ 0x%016llX:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); } } } - if (!clusterIndex.count) { - [endpointIndex removeObject:endpointID]; - } else if (clusterIndex.count != clusterIndexCount) { - BOOL success = [self _storeClusterIndex:clusterIndex forNodeID:nodeID endpointID:endpointID]; + if (clusterIndex.count != clusterIndexCopy.count) { + BOOL success; + if (clusterIndex.count) { + success = [self _storeClusterIndex:clusterIndexCopy forNodeID:nodeID endpointID:endpointID]; + } else { + [endpointIndexCopy removeObject:endpointID]; + success = [self _deleteClusterIndexForNodeID:nodeID endpointID:endpointID]; + } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed for clusterIndex"); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for clusterIndex @ 0x%016llX:0x%04X", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); } } } - if (!endpointIndex.count) { - [nodeIndex removeObject:nodeID]; - } else if (endpointIndex.count != endpointIndexCount) { - BOOL success = [self _storeEndpointIndex:endpointIndex forNodeID:nodeID]; + if (endpointIndex.count != endpointIndexCopy.count) { + BOOL success; + if (endpointIndexCopy.count) { + success = [self _storeEndpointIndex:endpointIndexCopy forNodeID:nodeID]; + } else { + [nodeIndexCopy removeObject:nodeID]; + success = [self _deleteEndpointIndexForNodeID:nodeID]; + } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed for endpointIndex"); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for endpointIndex @ 0x%016llX", nodeID.unsignedLongLongValue); } } } - if (!nodeIndex.count) { - [self _deleteNodeIndex]; - } else if (nodeIndex.count != nodeIndexCount) { - BOOL success = [self _storeNodeIndex:nodeIndex]; + if (nodeIndex.count != nodeIndexCopy.count) { + BOOL success; + if (!nodeIndex.count) { + success = [self _storeNodeIndex:nodeIndexCopy]; + } else { + success = [self _deleteNodeIndex]; + } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed for nodeIndex"); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for nodeIndex"); } } if (storeFailures) { - MTR_LOG_ERROR("Store failed in _pruneEmptyStoredAttributesBranches: %lu", (unsigned long) storeFailures); + MTR_LOG_ERROR("Store failed in _pruneEmptyStoredAttributesBranches: total %lu", static_cast(storeFailures)); } } @@ -584,6 +626,10 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS MTRAttributePath * path = dataValue[MTRAttributePathKey]; NSDictionary * value = dataValue[MTRDataKey]; +#if ATTRIBUTE_CACHE_VERBOSE_LOGGING + MTR_LOG_INFO("Attempt to store attribute value @ 0x%016llX:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); +#endif + BOOL storeFailed = NO; // Ensure node index exists NSArray * nodeIndex = [self _fetchNodeIndex]; @@ -609,7 +655,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for endpointIndex"); + MTR_LOG_INFO("Store failed for endpointIndex @ 0x%016llX", nodeID.unsignedLongLongValue); continue; } @@ -623,7 +669,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for clusterIndex"); + MTR_LOG_INFO("Store failed for clusterIndex @ 0x%016llX:0x%04X", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue); continue; } @@ -640,50 +686,80 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for attributeIndex"); + MTR_LOG_INFO("Store failed for attributeIndex @ 0x%016llX:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue); continue; } // Store value - storeFailed = [self _storeAttributeValue:value forNodeID:nodeID endpointID:path.endpoint clusterID:path.cluster attributeID:path.attribute]; + storeFailed = ![self _storeAttributeValue:value forNodeID:nodeID endpointID:path.endpoint clusterID:path.cluster attributeID:path.attribute]; if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for attribute value"); + MTR_LOG_INFO("Store failed for attribute value @ 0x%016llX:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); } } // In the rare event that store fails, allow all attribute store attempts to go through and prune empty branches at the end altogether. if (storeFailures) { [self _pruneEmptyStoredAttributesBranches]; - MTR_LOG_ERROR("Store failed in -storeAttributeValues:forNodeID: %lu", (unsigned long) storeFailures); + MTR_LOG_ERROR("Store failed in -storeAttributeValues:forNodeID: total %lu", static_cast(storeFailures)); } }); } - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID { + NSUInteger endpointsClearAttempts = 0; + NSUInteger clustersClearAttempts = 0; + NSUInteger attributesClearAttempts = 0; + NSUInteger endpointsCleared = 0; + NSUInteger clustersCleared = 0; + NSUInteger attributesCleared = 0; + // Fetch endpoint index NSArray * endpointIndex = [self _fetchEndpointIndexForNodeID:nodeID]; + endpointsClearAttempts += endpointIndex.count; for (NSNumber * endpointID in endpointIndex) { // Fetch cluster index NSArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID]; + clustersClearAttempts += clusterIndex.count; for (NSNumber * clusterID in clusterIndex) { // Fetch attribute index NSArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; + attributesClearAttempts += attributeIndex.count; for (NSNumber * attributeID in attributeIndex) { - [self _deleteAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; + BOOL success = [self _deleteAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; + if (!success) { + MTR_LOG_INFO("Delete failed for attribute value @ 0x%016llX:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); + } else { + attributesCleared++; + } } - [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; + BOOL success = [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; + if (!success) { + MTR_LOG_INFO("Delete failed for attributeIndex @ 0x%016llX:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + } else { + clustersCleared++; + } } - [self _deleteClusterIndexForNodeID:nodeID endpointID:endpointID]; + BOOL success = [self _deleteClusterIndexForNodeID:nodeID endpointID:endpointID]; + if (!success) { + MTR_LOG_INFO("Delete failed for clusterIndex @ 0x%016llX:0x%04X", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); + } else { + endpointsCleared++; + } } - [self _deleteEndpointIndexForNodeID:nodeID]; + BOOL success = [self _deleteEndpointIndexForNodeID:nodeID]; + if (!success) { + MTR_LOG_INFO("Delete failed for endpointrIndex @ 0x%016llX", nodeID.unsignedLongLongValue); + } + + MTR_LOG_INFO("clearStoredAttributesForNodeID: deleted endpoints %lu/%lu clusters %lu/%lu attributes %lu/%lu", static_cast(endpointsCleared), static_cast(endpointsClearAttempts), static_cast(clustersCleared), static_cast(clustersClearAttempts), static_cast(attributesCleared), static_cast(attributesClearAttempts)); } - (void)clearStoredAttributesForNodeID:(NSNumber *)nodeID @@ -703,7 +779,10 @@ - (void)clearAllStoredAttributes [self _clearStoredAttributesForNodeID:nodeID]; } - [self _deleteNodeIndex]; + BOOL success = [self _deleteNodeIndex]; + if (!success) { + MTR_LOG_INFO("Delete failed for nodeIndex"); + } }); } From e444ab9ed32355f772c9f76a8e2fea176ead65a1 Mon Sep 17 00:00:00 2001 From: Jeff Tung <100387939+jtung-apple@users.noreply.github.com> Date: Wed, 13 Mar 2024 08:41:52 -0700 Subject: [PATCH 2/6] Added unit test and minor fixes --- .../CHIP/MTRDeviceControllerDataStore.mm | 40 ++++++++++++------- .../CHIPTests/MTRPerControllerStorageTests.m | 28 +++++++++++++ .../TestHelpers/MTRTestDeclarations.h | 5 +++ 3 files changed, 59 insertions(+), 14 deletions(-) diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm index 08b537df784577..86cdfdd5ceffdd 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm @@ -556,22 +556,20 @@ - (void)_pruneEmptyStoredAttributesBranches if (attributeIndex.count != attributeIndexCopy.count) { BOOL success; - if (!success) { - if (attributeIndexCopy.count) { - success = [self _storeAttributeIndex:attributeIndexCopy forNodeID:nodeID endpointID:endpointID clusterID:clusterID]; - } else { - [clusterIndexCopy removeObject:clusterID]; - success = [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; - } - storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for attributeIndex @ 0x%016llX:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + if (attributeIndexCopy.count) { + success = [self _storeAttributeIndex:attributeIndexCopy forNodeID:nodeID endpointID:endpointID clusterID:clusterID]; + } else { + [clusterIndexCopy removeObject:clusterID]; + success = [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; } + storeFailures++; + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for attributeIndex (%lu) @ 0x%016llX:0x%04X:0x%08lX", static_cast(attributeIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); } } if (clusterIndex.count != clusterIndexCopy.count) { BOOL success; - if (clusterIndex.count) { + if (clusterIndexCopy.count) { success = [self _storeClusterIndex:clusterIndexCopy forNodeID:nodeID endpointID:endpointID]; } else { [endpointIndexCopy removeObject:endpointID]; @@ -579,7 +577,7 @@ - (void)_pruneEmptyStoredAttributesBranches } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for clusterIndex @ 0x%016llX:0x%04X", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for clusterIndex (%lu) @ 0x%016llX:0x%04X", static_cast(clusterIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); } } } @@ -594,21 +592,21 @@ - (void)_pruneEmptyStoredAttributesBranches } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for endpointIndex @ 0x%016llX", nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for endpointIndex (%lu) @ 0x%016llX", static_cast(endpointIndexCopy.count), nodeID.unsignedLongLongValue); } } } if (nodeIndex.count != nodeIndexCopy.count) { BOOL success; - if (!nodeIndex.count) { + if (nodeIndexCopy.count) { success = [self _storeNodeIndex:nodeIndexCopy]; } else { success = [self _deleteNodeIndex]; } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for nodeIndex"); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for nodeIndex (%lu)", static_cast(nodeIndexCopy.count)); } } @@ -766,6 +764,20 @@ - (void)clearStoredAttributesForNodeID:(NSNumber *)nodeID { dispatch_async(_storageDelegateQueue, ^{ [self _clearStoredAttributesForNodeID:nodeID]; + NSArray * nodeIndex = [self _fetchNodeIndex]; + NSMutableArray * nodeIndexCopy = nodeIndex.mutableCopy; + [nodeIndexCopy removeObject:nodeID]; + if (nodeIndex.count != nodeIndexCopy.count) { + BOOL success; + if (nodeIndexCopy.count) { + success = [self _storeNodeIndex:nodeIndexCopy]; + } else { + success = [self _deleteNodeIndex]; + } + if (!success) { + MTR_LOG_INFO("Store failed in clearStoredAttributesForNodeID for nodeIndex (%lu)", static_cast(nodeIndexCopy.count)); + } + } }); } diff --git a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m index 38795bcc8cef87..cb1bd73153faa5 100644 --- a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m +++ b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m @@ -1139,6 +1139,34 @@ - (void)test008_TestDataStoreDirect dataStoreValues = [controller.controllerDataStore getStoredAttributesForNodeID:@(1003)]; XCTAssertEqual(dataStoreValues.count, 0); + // Test MTRDeviceControllerDataStore _pruneEmptyStoredAttributesBranches + // - Clear cache + // - Store an attribute + // - Manually delete it from the user defaults + // - Call _pruneEmptyStoredAttributesBranches + [controller.controllerDataStore clearAllStoredAttributes]; + + NSArray * testAttribute = @[ + @{ MTRAttributePathKey : [MTRAttributePath attributePathWithEndpointID:@(1) clusterID:@(1) attributeID:@(1)], MTRDataKey : @ { MTRTypeKey : MTRUnsignedIntegerValueType, MTRValueKey : @(111) } }, + ]; + [controller.controllerDataStore storeAttributeValues:testAttribute forNodeID:@(2001)]; + NSString * testAttributeValueKey = [controller.controllerDataStore _attributeValueKeyForNodeID:@(2001) endpointID:@(1) clusterID:@(1) attributeID:@(1)]; + [storageDelegate controller:controller removeValueForKey:testAttributeValueKey securityLevel:MTRStorageSecurityLevelSecure sharingType:MTRStorageSharingTypeNotShared]; + [controller.controllerDataStore _pruneEmptyStoredAttributesBranches]; + + // Now check the indexes are pruned + NSString * testAttributeIndexKey = [controller.controllerDataStore _attributeIndexKeyForNodeID:@(2001) endpointID:@(1) clusterID:@(1)]; + id testAttributeIndex = [storageDelegate controller:controller valueForKey:testAttributeIndexKey securityLevel:MTRStorageSecurityLevelSecure sharingType:MTRStorageSharingTypeNotShared]; + XCTAssertNil(testAttributeIndex); + NSString * testClusterIndexKey = [controller.controllerDataStore _clusterIndexKeyForNodeID:@(2001) endpointID:@(1)]; + id testClusterIndex = [storageDelegate controller:controller valueForKey:testClusterIndexKey securityLevel:MTRStorageSecurityLevelSecure sharingType:MTRStorageSharingTypeNotShared]; + XCTAssertNil(testClusterIndex); + NSString * testEndpointIndexKey = [controller.controllerDataStore _endpointIndexKeyForNodeID:@(2001)]; + id testEndpointIndex = [storageDelegate controller:controller valueForKey:testEndpointIndexKey securityLevel:MTRStorageSecurityLevelSecure sharingType:MTRStorageSharingTypeNotShared]; + XCTAssertNil(testEndpointIndex); + id testNodeIndex = [storageDelegate controller:controller valueForKey:@"attrCacheNodeIndex" securityLevel:MTRStorageSecurityLevelSecure sharingType:MTRStorageSharingTypeNotShared]; + XCTAssertNil(testNodeIndex); + [controller shutdown]; XCTAssertFalse([controller isRunning]); } diff --git a/src/darwin/Framework/CHIPTests/TestHelpers/MTRTestDeclarations.h b/src/darwin/Framework/CHIPTests/TestHelpers/MTRTestDeclarations.h index 5b77d0ec06aad7..86e4564e45f8c0 100644 --- a/src/darwin/Framework/CHIPTests/TestHelpers/MTRTestDeclarations.h +++ b/src/darwin/Framework/CHIPTests/TestHelpers/MTRTestDeclarations.h @@ -28,6 +28,11 @@ NS_ASSUME_NONNULL_BEGIN - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NSNumber *)nodeID; - (void)clearStoredAttributesForNodeID:(NSNumber *)nodeID; - (void)clearAllStoredAttributes; +- (void)_pruneEmptyStoredAttributesBranches; +- (NSString *)_endpointIndexKeyForNodeID:(NSNumber *)nodeID; +- (NSString *)_clusterIndexKeyForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID; +- (NSString *)_attributeIndexKeyForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID clusterID:(NSNumber *)clusterID; +- (NSString *)_attributeValueKeyForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID clusterID:(NSNumber *)clusterID attributeID:(NSNumber *)attributeID; @end // Declare internal methods for testing From 0ddd4ac421710926bbfe99f8e33fb0d3bcb886df Mon Sep 17 00:00:00 2001 From: Jeff Tung <100387939+jtung-apple@users.noreply.github.com> Date: Wed, 13 Mar 2024 08:51:54 -0700 Subject: [PATCH 3/6] Unit test fix --- .../Framework/CHIP/MTRDeviceControllerDataStore.mm | 9 +++++++++ .../Framework/CHIPTests/MTRPerControllerStorageTests.m | 2 +- .../CHIPTests/TestHelpers/MTRTestDeclarations.h | 2 +- 3 files changed, 11 insertions(+), 2 deletions(-) diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm index 86cdfdd5ceffdd..4fa9fd0f8d1d1f 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm @@ -521,6 +521,15 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * return attributesToReturn; } +#ifdef DEBUG +- (void)unitTestPruneEmptyStoredAttributesBranches +{ + dispatch_sync(_storageDelegateQueue, ^{ + [self _pruneEmptyStoredAttributesBranches]; + }); +} +#endif + - (void)_pruneEmptyStoredAttributesBranches { dispatch_assert_queue(_storageDelegateQueue); diff --git a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m index cb1bd73153faa5..a81f68b6185cfb 100644 --- a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m +++ b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m @@ -1152,7 +1152,7 @@ - (void)test008_TestDataStoreDirect [controller.controllerDataStore storeAttributeValues:testAttribute forNodeID:@(2001)]; NSString * testAttributeValueKey = [controller.controllerDataStore _attributeValueKeyForNodeID:@(2001) endpointID:@(1) clusterID:@(1) attributeID:@(1)]; [storageDelegate controller:controller removeValueForKey:testAttributeValueKey securityLevel:MTRStorageSecurityLevelSecure sharingType:MTRStorageSharingTypeNotShared]; - [controller.controllerDataStore _pruneEmptyStoredAttributesBranches]; + [controller.controllerDataStore unitTestPruneEmptyStoredAttributesBranches]; // Now check the indexes are pruned NSString * testAttributeIndexKey = [controller.controllerDataStore _attributeIndexKeyForNodeID:@(2001) endpointID:@(1) clusterID:@(1)]; diff --git a/src/darwin/Framework/CHIPTests/TestHelpers/MTRTestDeclarations.h b/src/darwin/Framework/CHIPTests/TestHelpers/MTRTestDeclarations.h index 86e4564e45f8c0..02a711ee183470 100644 --- a/src/darwin/Framework/CHIPTests/TestHelpers/MTRTestDeclarations.h +++ b/src/darwin/Framework/CHIPTests/TestHelpers/MTRTestDeclarations.h @@ -28,7 +28,7 @@ NS_ASSUME_NONNULL_BEGIN - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NSNumber *)nodeID; - (void)clearStoredAttributesForNodeID:(NSNumber *)nodeID; - (void)clearAllStoredAttributes; -- (void)_pruneEmptyStoredAttributesBranches; +- (void)unitTestPruneEmptyStoredAttributesBranches; - (NSString *)_endpointIndexKeyForNodeID:(NSNumber *)nodeID; - (NSString *)_clusterIndexKeyForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID; - (NSString *)_attributeIndexKeyForNodeID:(NSNumber *)nodeID endpointID:(NSNumber *)endpointID clusterID:(NSNumber *)clusterID; From fb399d4e30d9142f5168219321920962928abb02 Mon Sep 17 00:00:00 2001 From: Jeff Tung <100387939+jtung-apple@users.noreply.github.com> Date: Wed, 13 Mar 2024 09:10:25 -0700 Subject: [PATCH 4/6] Addressed review comments --- .../CHIP/MTRDeviceControllerDataStore.mm | 44 +++++++++---------- 1 file changed, 22 insertions(+), 22 deletions(-) diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm index 4fa9fd0f8d1d1f..66a2838026c029 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm @@ -467,7 +467,7 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * [self clearStoredAttributesForNodeID:nodeID]; } - MTR_LOG_INFO("Fetch got no value for endpointIndex @ 0x%016llX", nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Fetch got no value for endpointIndex @ %llu", nodeID.unsignedLongLongValue); attributesToReturn = nil; return; } @@ -476,7 +476,7 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * NSArray * endpointIndex = [self _fetchEndpointIndexForNodeID:nodeID]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Fetch got %lu values for endpointIndex @ 0x%016llX", static_cast(endpointIndex.count), nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Fetch got %lu values for endpointIndex @ %llu", static_cast(endpointIndex.count), nodeID.unsignedLongLongValue); #endif for (NSNumber * endpointID in endpointIndex) { @@ -484,7 +484,7 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * NSArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Fetch got %lu values for clusterIndex @ 0x%016llX:0x%04X", static_cast(clusterIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); + MTR_LOG_INFO("Fetch got %lu values for clusterIndex @ %llu:0x%04X", static_cast(clusterIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); #endif for (NSNumber * clusterID in clusterIndex) { @@ -492,14 +492,14 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * NSArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Fetch got %lu values for attributeIndex @ 0x%016llX:0x%04X:0x%08lX", static_cast(attributeIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + MTR_LOG_INFO("Fetch got %lu values for attributeIndex @ %llu:0x%04X:0x%08lX", static_cast(attributeIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); #endif for (NSNumber * attributeID in attributeIndex) { NSDictionary * value = [self _fetchAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Fetch got %u values for attribute value @ 0x%016llX:0x%04X:0x%08lX:0x%08lX", value ? 1 : 0, nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); + MTR_LOG_INFO("Fetch got %u values for attribute value @ %llu:0x%04X:0x%08lX:0x%08lX", value ? 1 : 0, nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); #endif if (value) { @@ -537,7 +537,7 @@ - (void)_pruneEmptyStoredAttributesBranches NSUInteger storeFailures = 0; // Fetch node index - NSArray * nodeIndex = [self _fetchNodeIndex].mutableCopy; + NSArray * nodeIndex = [self _fetchNodeIndex]; NSMutableArray * nodeIndexCopy = nodeIndex.mutableCopy; for (NSNumber * nodeID in nodeIndex) { @@ -547,12 +547,12 @@ - (void)_pruneEmptyStoredAttributesBranches for (NSNumber * endpointID in endpointIndex) { // Fetch endpoint index - NSArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID].mutableCopy; + NSArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID]; NSMutableArray * clusterIndexCopy = clusterIndex.mutableCopy; for (NSNumber * clusterID in clusterIndex) { // Fetch endpoint index - NSArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID].mutableCopy; + NSArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; NSMutableArray * attributeIndexCopy = attributeIndex.mutableCopy; for (NSNumber * attributeID in attributeIndex) { @@ -572,7 +572,7 @@ - (void)_pruneEmptyStoredAttributesBranches success = [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; } storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for attributeIndex (%lu) @ 0x%016llX:0x%04X:0x%08lX", static_cast(attributeIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for attributeIndex (%lu) @ %llu:0x%04X:0x%08lX", static_cast(attributeIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); } } @@ -586,7 +586,7 @@ - (void)_pruneEmptyStoredAttributesBranches } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for clusterIndex (%lu) @ 0x%016llX:0x%04X", static_cast(clusterIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for clusterIndex (%lu) @ %llu:0x%04X", static_cast(clusterIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); } } } @@ -601,7 +601,7 @@ - (void)_pruneEmptyStoredAttributesBranches } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for endpointIndex (%lu) @ 0x%016llX", static_cast(endpointIndexCopy.count), nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for endpointIndex (%lu) @ %llu", static_cast(endpointIndexCopy.count), nodeID.unsignedLongLongValue); } } } @@ -620,7 +620,7 @@ - (void)_pruneEmptyStoredAttributesBranches } if (storeFailures) { - MTR_LOG_ERROR("Store failed in _pruneEmptyStoredAttributesBranches: total %lu", static_cast(storeFailures)); + MTR_LOG_ERROR("Store failed in _pruneEmptyStoredAttributesBranches: failure count %lu", static_cast(storeFailures)); } } @@ -634,7 +634,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS NSDictionary * value = dataValue[MTRDataKey]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Attempt to store attribute value @ 0x%016llX:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); + MTR_LOG_INFO("Attempt to store attribute value @ %llu:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); #endif BOOL storeFailed = NO; @@ -662,7 +662,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for endpointIndex @ 0x%016llX", nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Store failed for endpointIndex @ %llu", nodeID.unsignedLongLongValue); continue; } @@ -676,7 +676,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for clusterIndex @ 0x%016llX:0x%04X", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue); + MTR_LOG_INFO("Store failed for clusterIndex @ %llu:0x%04X", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue); continue; } @@ -693,7 +693,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for attributeIndex @ 0x%016llX:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue); + MTR_LOG_INFO("Store failed for attributeIndex @ %llu:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue); continue; } @@ -701,14 +701,14 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS storeFailed = ![self _storeAttributeValue:value forNodeID:nodeID endpointID:path.endpoint clusterID:path.cluster attributeID:path.attribute]; if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for attribute value @ 0x%016llX:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); + MTR_LOG_INFO("Store failed for attribute value @ %llu:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); } } // In the rare event that store fails, allow all attribute store attempts to go through and prune empty branches at the end altogether. if (storeFailures) { [self _pruneEmptyStoredAttributesBranches]; - MTR_LOG_ERROR("Store failed in -storeAttributeValues:forNodeID: total %lu", static_cast(storeFailures)); + MTR_LOG_ERROR("Store failed in -storeAttributeValues:forNodeID: failure count %lu", static_cast(storeFailures)); } }); } @@ -739,7 +739,7 @@ - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID for (NSNumber * attributeID in attributeIndex) { BOOL success = [self _deleteAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; if (!success) { - MTR_LOG_INFO("Delete failed for attribute value @ 0x%016llX:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); + MTR_LOG_INFO("Delete failed for attribute value @ %llu:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); } else { attributesCleared++; } @@ -747,7 +747,7 @@ - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID BOOL success = [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; if (!success) { - MTR_LOG_INFO("Delete failed for attributeIndex @ 0x%016llX:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + MTR_LOG_INFO("Delete failed for attributeIndex @ %llu:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); } else { clustersCleared++; } @@ -755,7 +755,7 @@ - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID BOOL success = [self _deleteClusterIndexForNodeID:nodeID endpointID:endpointID]; if (!success) { - MTR_LOG_INFO("Delete failed for clusterIndex @ 0x%016llX:0x%04X", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); + MTR_LOG_INFO("Delete failed for clusterIndex @ %llu:0x%04X", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); } else { endpointsCleared++; } @@ -763,7 +763,7 @@ - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID BOOL success = [self _deleteEndpointIndexForNodeID:nodeID]; if (!success) { - MTR_LOG_INFO("Delete failed for endpointrIndex @ 0x%016llX", nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Delete failed for endpointrIndex @ %llu", nodeID.unsignedLongLongValue); } MTR_LOG_INFO("clearStoredAttributesForNodeID: deleted endpoints %lu/%lu clusters %lu/%lu attributes %lu/%lu", static_cast(endpointsCleared), static_cast(endpointsClearAttempts), static_cast(clustersCleared), static_cast(clustersClearAttempts), static_cast(attributesCleared), static_cast(attributesClearAttempts)); From 1191da76bf1d0b98a2234c92489d8bf76963c124 Mon Sep 17 00:00:00 2001 From: Jeff Tung <100387939+jtung-apple@users.noreply.github.com> Date: Wed, 13 Mar 2024 10:28:29 -0700 Subject: [PATCH 5/6] Fixed / clarified logging for nodeID, endpoint, cluster, attribute --- .../CHIP/MTRDeviceControllerDataStore.mm | 48 ++++++++++--------- 1 file changed, 25 insertions(+), 23 deletions(-) diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm index 66a2838026c029..26d68921591f75 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm @@ -467,7 +467,7 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * [self clearStoredAttributesForNodeID:nodeID]; } - MTR_LOG_INFO("Fetch got no value for endpointIndex @ %llu", nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Fetch got no value for endpointIndex @ node 0x%016llX", nodeID.unsignedLongLongValue); attributesToReturn = nil; return; } @@ -476,7 +476,7 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * NSArray * endpointIndex = [self _fetchEndpointIndexForNodeID:nodeID]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Fetch got %lu values for endpointIndex @ %llu", static_cast(endpointIndex.count), nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Fetch got %lu values for endpointIndex @ node 0x%016llX", static_cast(endpointIndex.count), nodeID.unsignedLongLongValue); #endif for (NSNumber * endpointID in endpointIndex) { @@ -484,7 +484,7 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * NSArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Fetch got %lu values for clusterIndex @ %llu:0x%04X", static_cast(clusterIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); + MTR_LOG_INFO("Fetch got %lu values for clusterIndex @ node 0x%016llX %u", static_cast(clusterIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); #endif for (NSNumber * clusterID in clusterIndex) { @@ -492,14 +492,14 @@ - (BOOL)_deleteAttributeValueForNodeID:(NSNumber *)nodeID endpointID:(NSNumber * NSArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Fetch got %lu values for attributeIndex @ %llu:0x%04X:0x%08lX", static_cast(attributeIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + MTR_LOG_INFO("Fetch got %lu values for attributeIndex @ node 0x%016llX endpoint %u cluster 0x%08lX", static_cast(attributeIndex.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); #endif for (NSNumber * attributeID in attributeIndex) { NSDictionary * value = [self _fetchAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Fetch got %u values for attribute value @ %llu:0x%04X:0x%08lX:0x%08lX", value ? 1 : 0, nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); + MTR_LOG_INFO("Fetch got %u values for attribute value @ node 0x%016llX endpoint %u cluster 0x%08lX attribute 0x%08lX", value ? 1 : 0, nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); #endif if (value) { @@ -538,22 +538,22 @@ - (void)_pruneEmptyStoredAttributesBranches // Fetch node index NSArray * nodeIndex = [self _fetchNodeIndex]; - NSMutableArray * nodeIndexCopy = nodeIndex.mutableCopy; + NSMutableArray * nodeIndexCopy = [nodeIndex mutableCopy]; for (NSNumber * nodeID in nodeIndex) { // Fetch endpoint index NSArray * endpointIndex = [self _fetchEndpointIndexForNodeID:nodeID]; - NSMutableArray * endpointIndexCopy = endpointIndex.mutableCopy; + NSMutableArray * endpointIndexCopy = [endpointIndex mutableCopy]; for (NSNumber * endpointID in endpointIndex) { // Fetch endpoint index NSArray * clusterIndex = [self _fetchClusterIndexForNodeID:nodeID endpointID:endpointID]; - NSMutableArray * clusterIndexCopy = clusterIndex.mutableCopy; + NSMutableArray * clusterIndexCopy = [clusterIndex mutableCopy]; for (NSNumber * clusterID in clusterIndex) { // Fetch endpoint index NSArray * attributeIndex = [self _fetchAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; - NSMutableArray * attributeIndexCopy = attributeIndex.mutableCopy; + NSMutableArray * attributeIndexCopy = [attributeIndex mutableCopy]; for (NSNumber * attributeID in attributeIndex) { NSDictionary * value = [self _fetchAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; @@ -571,8 +571,10 @@ - (void)_pruneEmptyStoredAttributesBranches [clusterIndexCopy removeObject:clusterID]; success = [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; } - storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for attributeIndex (%lu) @ %llu:0x%04X:0x%08lX", static_cast(attributeIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + if (!success) { + storeFailures++; + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for attributeIndex (%lu) @ node 0x%016llX endpoint %u cluster 0x%08lX", static_cast(attributeIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + } } } @@ -586,7 +588,7 @@ - (void)_pruneEmptyStoredAttributesBranches } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for clusterIndex (%lu) @ %llu:0x%04X", static_cast(clusterIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for clusterIndex (%lu) @ node 0x%016llX endpoint %u", static_cast(clusterIndexCopy.count), nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); } } } @@ -601,7 +603,7 @@ - (void)_pruneEmptyStoredAttributesBranches } if (!success) { storeFailures++; - MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for endpointIndex (%lu) @ %llu", static_cast(endpointIndexCopy.count), nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Store failed in _pruneEmptyStoredAttributesBranches for endpointIndex (%lu) @ node 0x%016llX", static_cast(endpointIndexCopy.count), nodeID.unsignedLongLongValue); } } } @@ -634,7 +636,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS NSDictionary * value = dataValue[MTRDataKey]; #if ATTRIBUTE_CACHE_VERBOSE_LOGGING - MTR_LOG_INFO("Attempt to store attribute value @ %llu:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); + MTR_LOG_INFO("Attempt to store attribute value @ node 0x%016llX endpoint %u cluster 0x%08lX attribute 0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); #endif BOOL storeFailed = NO; @@ -662,7 +664,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for endpointIndex @ %llu", nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Store failed for endpointIndex @ node 0x%016llX", nodeID.unsignedLongLongValue); continue; } @@ -676,7 +678,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for clusterIndex @ %llu:0x%04X", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue); + MTR_LOG_INFO("Store failed for clusterIndex @ node 0x%016llX endpoint %u", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue); continue; } @@ -693,7 +695,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS } if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for attributeIndex @ %llu:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue); + MTR_LOG_INFO("Store failed for attributeIndex @ node 0x%016llX endpoint %u cluster 0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue); continue; } @@ -701,7 +703,7 @@ - (void)storeAttributeValues:(NSArray *)dataValues forNodeID:(NS storeFailed = ![self _storeAttributeValue:value forNodeID:nodeID endpointID:path.endpoint clusterID:path.cluster attributeID:path.attribute]; if (storeFailed) { storeFailures++; - MTR_LOG_INFO("Store failed for attribute value @ %llu:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); + MTR_LOG_INFO("Store failed for attribute value @ node 0x%016llX endpoint %u cluster 0x%08lX attribute 0x%08lX", nodeID.unsignedLongLongValue, path.endpoint.unsignedShortValue, path.cluster.unsignedLongValue, path.attribute.unsignedLongValue); } } @@ -739,7 +741,7 @@ - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID for (NSNumber * attributeID in attributeIndex) { BOOL success = [self _deleteAttributeValueForNodeID:nodeID endpointID:endpointID clusterID:clusterID attributeID:attributeID]; if (!success) { - MTR_LOG_INFO("Delete failed for attribute value @ %llu:0x%04X:0x%08lX:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); + MTR_LOG_INFO("Delete failed for attribute value @ node 0x%016llX endpoint %u cluster 0x%08lX attribute 0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue, attributeID.unsignedLongValue); } else { attributesCleared++; } @@ -747,7 +749,7 @@ - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID BOOL success = [self _deleteAttributeIndexForNodeID:nodeID endpointID:endpointID clusterID:clusterID]; if (!success) { - MTR_LOG_INFO("Delete failed for attributeIndex @ %llu:0x%04X:0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); + MTR_LOG_INFO("Delete failed for attributeIndex @ node 0x%016llX endpoint %u cluster 0x%08lX", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue, clusterID.unsignedLongValue); } else { clustersCleared++; } @@ -755,7 +757,7 @@ - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID BOOL success = [self _deleteClusterIndexForNodeID:nodeID endpointID:endpointID]; if (!success) { - MTR_LOG_INFO("Delete failed for clusterIndex @ %llu:0x%04X", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); + MTR_LOG_INFO("Delete failed for clusterIndex @ node 0x%016llX endpoint %u", nodeID.unsignedLongLongValue, endpointID.unsignedShortValue); } else { endpointsCleared++; } @@ -763,7 +765,7 @@ - (void)_clearStoredAttributesForNodeID:(NSNumber *)nodeID BOOL success = [self _deleteEndpointIndexForNodeID:nodeID]; if (!success) { - MTR_LOG_INFO("Delete failed for endpointrIndex @ %llu", nodeID.unsignedLongLongValue); + MTR_LOG_INFO("Delete failed for endpointrIndex @ node 0x%016llX", nodeID.unsignedLongLongValue); } MTR_LOG_INFO("clearStoredAttributesForNodeID: deleted endpoints %lu/%lu clusters %lu/%lu attributes %lu/%lu", static_cast(endpointsCleared), static_cast(endpointsClearAttempts), static_cast(clustersCleared), static_cast(clustersClearAttempts), static_cast(attributesCleared), static_cast(attributesClearAttempts)); @@ -774,7 +776,7 @@ - (void)clearStoredAttributesForNodeID:(NSNumber *)nodeID dispatch_async(_storageDelegateQueue, ^{ [self _clearStoredAttributesForNodeID:nodeID]; NSArray * nodeIndex = [self _fetchNodeIndex]; - NSMutableArray * nodeIndexCopy = nodeIndex.mutableCopy; + NSMutableArray * nodeIndexCopy = [nodeIndex mutableCopy]; [nodeIndexCopy removeObject:nodeID]; if (nodeIndex.count != nodeIndexCopy.count) { BOOL success; From 62ff45ed264cd0b87e562248f656639428fae4e7 Mon Sep 17 00:00:00 2001 From: Jeff Tung <100387939+jtung-apple@users.noreply.github.com> Date: Wed, 13 Mar 2024 11:05:53 -0700 Subject: [PATCH 6/6] Fixed unit test race condition --- .../Framework/CHIPTests/MTRPerControllerStorageTests.m | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m index a81f68b6185cfb..efa53d9dabcefb 100644 --- a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m +++ b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m @@ -1142,7 +1142,7 @@ - (void)test008_TestDataStoreDirect // Test MTRDeviceControllerDataStore _pruneEmptyStoredAttributesBranches // - Clear cache // - Store an attribute - // - Manually delete it from the user defaults + // - Manually delete it from the test storage delegate // - Call _pruneEmptyStoredAttributesBranches [controller.controllerDataStore clearAllStoredAttributes]; @@ -1150,8 +1150,12 @@ - (void)test008_TestDataStoreDirect @{ MTRAttributePathKey : [MTRAttributePath attributePathWithEndpointID:@(1) clusterID:@(1) attributeID:@(1)], MTRDataKey : @ { MTRTypeKey : MTRUnsignedIntegerValueType, MTRValueKey : @(111) } }, ]; [controller.controllerDataStore storeAttributeValues:testAttribute forNodeID:@(2001)]; - NSString * testAttributeValueKey = [controller.controllerDataStore _attributeValueKeyForNodeID:@(2001) endpointID:@(1) clusterID:@(1) attributeID:@(1)]; - [storageDelegate controller:controller removeValueForKey:testAttributeValueKey securityLevel:MTRStorageSecurityLevelSecure sharingType:MTRStorageSharingTypeNotShared]; + + // store is async, so remove on the same queue to ensure order + dispatch_sync(_storageQueue, ^{ + NSString * testAttributeValueKey = [controller.controllerDataStore _attributeValueKeyForNodeID:@(2001) endpointID:@(1) clusterID:@(1) attributeID:@(1)]; + [storageDelegate controller:controller removeValueForKey:testAttributeValueKey securityLevel:MTRStorageSecurityLevelSecure sharingType:MTRStorageSharingTypeNotShared]; + }); [controller.controllerDataStore unitTestPruneEmptyStoredAttributesBranches]; // Now check the indexes are pruned