Skip to content

Commit

Permalink
Added tests and address PR comment
Browse files Browse the repository at this point in the history
  • Loading branch information
@jtung-apple
jtung-apple committed Jul 19, 2024
1 parent f6e0179 commit f6358cd
Show file tree
Hide file tree
Showing 4 changed files with 114 additions and 41 deletions.
32 changes: 30 additions & 2 deletions src/darwin/Framework/CHIP/MTRDevice.mm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2112,6 +2112,22 @@ - (void)unitTestClearClusterData
}
#endif

- (void)_reconcilePersistedClustersWithStorage
{
os_unfair_lock_assert_owner(&self->_lock);

NSMutableSet * clusterPathsToRemove = [NSMutableSet set];
for (MTRClusterPath * clusterPath in _persistedClusters) {
MTRDeviceClusterData * data = [_deviceController.controllerDataStore getStoredClusterDataForNodeID:_nodeID endpointID:clusterPath.endpoint clusterID:clusterPath.cluster];
if (!data) {
[clusterPathsToRemove addObject:clusterPath];
}
}

MTR_LOG_ERROR("%@ ", self);
[_persistedClusters minusSet:clusterPathsToRemove];
}

- (nullable MTRDeviceClusterData *)_clusterDataForPath:(MTRClusterPath *)clusterPath
{
os_unfair_lock_assert_owner(&self->_lock);
Expand Down Expand Up @@ -2144,10 +2160,15 @@ - (nullable MTRDeviceClusterData *)_clusterDataForPath:(MTRClusterPath *)cluster

// Page in the stored value for the data.
MTRDeviceClusterData * data = [_deviceController.controllerDataStore getStoredClusterDataForNodeID:_nodeID endpointID:clusterPath.endpoint clusterID:clusterPath.cluster];
MTR_LOG("%@ cluster path %@ cache miss - load from storage success %@", self, clusterPath, YES_NO(data));
if (data != nil) {
[_persistedClusterData setObject:data forKey:clusterPath];
} else {
// If clusterPath is in _persistedClusters and the data store returns nil for it, then the in-memory cache is now not dependable, and subscription should be reset and reestablished to reload cache from device

// First make sure _persistedClusters is consistent with storage, so repeated calls don't immediately re-trigger this
[self _reconcilePersistedClustersWithStorage];

[self _resetSubscriptionWithReasonString:[NSString stringWithFormat:@"Data store has no data for cluster %@", clusterPath]];
}

Expand Down Expand Up @@ -3798,14 +3819,21 @@ - (void)_storePersistedDeviceData
}

#ifdef DEBUG
- (MTRDeviceClusterData *)_getClusterDataForPath:(MTRClusterPath *)path
- (MTRDeviceClusterData *)unitTestGetClusterDataForPath:(MTRClusterPath *)path
{
std::lock_guard lock(_lock);

return [[self _clusterDataForPath:path] copy];
}

- (BOOL)_clusterHasBeenPersisted:(MTRClusterPath *)path
- (NSSet<MTRClusterPath *> *)unitTestGetPersistedClusters
{
std::lock_guard lock(_lock);

return [_persistedClusters copy];
}

- (BOOL)unitTestClusterHasBeenPersisted:(MTRClusterPath *)path
{
std::lock_guard lock(_lock);

Expand Down
70 changes: 39 additions & 31 deletions src/darwin/Framework/CHIP/MTRDeviceController.mm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -255,7 +255,7 @@ - (instancetype)initWithFactory:(MTRDeviceControllerFactory *)factory
return nil;
}

// Provide a way to test different subscription pool sizes without code change
// Provide a way to test different subscription pool sizes without code/ change
NSUserDefaults * defaults = [NSUserDefaults standardUserDefaults];
if ([defaults objectForKey:kDefaultSubscriptionPoolSizeOverrideKey]) {
NSInteger subscriptionPoolSizeOverride = [defaults integerForKey:kDefaultSubscriptionPoolSizeOverrideKey];
Expand All @@ -272,7 +272,7 @@ - (instancetype)initWithFactory:(MTRDeviceControllerFactory *)factory
concurrentSubscriptionPoolSize = 1;
}

MTR_LOG("Setting up pool size of MTRDeviceController with: %lu", static_cast<unsigned long>(concurrentSubscriptionPoolSize));
MTR_LOG("%@ Setting up pool size of MTRDeviceController with: %lu", self, static_cast<unsigned long>(concurrentSubscriptionPoolSize));

_concurrentSubscriptionPool = [[MTRAsyncWorkQueue alloc] initWithContext:self width:concurrentSubscriptionPoolSize];

Expand All @@ -283,13 +283,19 @@ - (instancetype)initWithFactory:(MTRDeviceControllerFactory *)factory
return self;
}

- (NSString *)description
{
return [NSString stringWithFormat:@"<MTRDeviceController: %p uuid %@>", self, _uniqueIdentifier];
}

- (BOOL)isRunning
{
return _cppCommissioner != nullptr;
}

- (void)shutdown
{
MTR_LOG("%@ shutdown called", self);
if (_cppCommissioner == nullptr) {
// Already shut down.
return;
Expand Down Expand Up @@ -393,7 +399,7 @@ - (BOOL)startup:(MTRDeviceControllerStartupParamsInternal *)startupParams
{
__block BOOL commissionerInitialized = NO;
if ([self isRunning]) {
MTR_LOG_ERROR("Unexpected duplicate call to startup");
MTR_LOG_ERROR("%@ Unexpected duplicate call to startup", self);
return NO;
}

Expand All @@ -404,24 +410,24 @@ - (BOOL)startup:(MTRDeviceControllerStartupParamsInternal *)startupParams

if (startupParams.vendorID == nil || [startupParams.vendorID unsignedShortValue] == chip::VendorId::Common) {
// Shouldn't be using the "standard" vendor ID for actual devices.
MTR_LOG_ERROR("%@ is not a valid vendorID to initialize a device controller with", startupParams.vendorID);
MTR_LOG_ERROR("%@ %@ is not a valid vendorID to initialize a device controller with", self, startupParams.vendorID);
return;
}

if (startupParams.operationalCertificate == nil && startupParams.nodeID == nil) {
MTR_LOG_ERROR("Can't start a controller if we don't know what node id it is");
MTR_LOG_ERROR("%@ Can't start a controller if we don't know what node id it is", self);
return;
}

if ([startupParams keypairsMatchCertificates] == NO) {
MTR_LOG_ERROR("Provided keypairs do not match certificates");
MTR_LOG_ERROR("%@ Provided keypairs do not match certificates", self);
return;
}

if (startupParams.operationalCertificate != nil && startupParams.operationalKeypair == nil
&& (!startupParams.fabricIndex.HasValue()
|| !startupParams.keystore->HasOpKeypairForFabric(startupParams.fabricIndex.Value()))) {
MTR_LOG_ERROR("Have no operational keypair for our operational certificate");
MTR_LOG_ERROR("%@ Have no operational keypair for our operational certificate", self);
return;
}

Expand Down Expand Up @@ -584,9 +590,12 @@ - (BOOL)startup:(MTRDeviceControllerStartupParamsInternal *)startupParams

self->_storedFabricIndex = fabricIdx;
commissionerInitialized = YES;

MTR_LOG("%@ startup succeeded for nodeID 0x%016llX", self, self->_cppCommissioner->GetNodeId());
});

if (commissionerInitialized == NO) {
MTR_LOG_ERROR("%@ startup failed", self);
[self cleanupAfterStartup];
return NO;
}
Expand All @@ -597,22 +606,22 @@ - (BOOL)startup:(MTRDeviceControllerStartupParamsInternal *)startupParams
// above.
if (![self setOperationalCertificateIssuer:startupParams.operationalCertificateIssuer
queue:startupParams.operationalCertificateIssuerQueue]) {
MTR_LOG_ERROR("operationalCertificateIssuer and operationalCertificateIssuerQueue must both be nil or both be non-nil");
MTR_LOG_ERROR("%@ operationalCertificateIssuer and operationalCertificateIssuerQueue must both be nil or both be non-nil", self);
[self cleanupAfterStartup];
return NO;
}

if (_controllerDataStore) {
// If the storage delegate supports the bulk read API, then a dictionary of nodeID => cluster data dictionary would be passed to the handler. Otherwise this would be a no-op, and stored attributes for MTRDevice objects will be loaded lazily in -deviceForNodeID:.
[_controllerDataStore fetchAttributeDataForAllDevices:^(NSDictionary<NSNumber *, NSDictionary<MTRClusterPath *, MTRDeviceClusterData *> *> * _Nonnull clusterDataByNode) {
MTR_LOG("Loaded attribute values for %lu nodes from storage for controller uuid %@", static_cast<unsigned long>(clusterDataByNode.count), self->_uniqueIdentifier);
MTR_LOG("%@ Loaded attribute values for %lu nodes from storage for controller uuid %@", self, static_cast<unsigned long>(clusterDataByNode.count), self->_uniqueIdentifier);

std::lock_guard lock(self->_deviceMapLock);
NSMutableArray * deviceList = [NSMutableArray array];
for (NSNumber * nodeID in clusterDataByNode) {
NSDictionary * clusterData = clusterDataByNode[nodeID];
MTRDevice * device = [self _setupDeviceForNodeID:nodeID prefetchedClusterData:clusterData];
MTR_LOG("Loaded %lu cluster data from storage for %@", static_cast<unsigned long>(clusterData.count), device);
MTR_LOG("%@ Loaded %lu cluster data from storage for %@", self, static_cast<unsigned long>(clusterData.count), device);

[deviceList addObject:device];
}
Expand All @@ -623,7 +632,7 @@ - (BOOL)startup:(MTRDeviceControllerStartupParamsInternal *)startupParams
// Note that this is just an optimization to avoid throwing the information away and immediately
// re-reading it from storage.
dispatch_after(dispatch_time(DISPATCH_TIME_NOW, (int64_t) (kSecondsToWaitBeforeAPIClientRetainsMTRDevice * NSEC_PER_SEC)), dispatch_get_main_queue(), ^{
MTR_LOG("MTRDeviceController: un-retain devices loaded at startup %lu", static_cast<unsigned long>(deviceList.count));
MTR_LOG("%@ un-retain devices loaded at startup %lu", self, static_cast<unsigned long>(deviceList.count));
});
}];
}
Expand All @@ -638,7 +647,7 @@ - (NSNumber *)controllerNodeID

NSNumber * nodeID = [self syncRunOnWorkQueueWithReturnValue:block error:nil];
if (!nodeID) {
MTR_LOG_ERROR("A controller has no node id if it has not been started");
MTR_LOG_ERROR("%@ A controller has no node id if it has not been started", self);
}

return nodeID;
Expand Down Expand Up @@ -707,7 +716,7 @@ - (BOOL)setupCommissioningSessionWithDiscoveredDevice:(MTRCommissionableBrowserR
newNodeID:(NSNumber *)newNodeID
error:(NSError * __autoreleasing *)error
{
MTR_LOG("Setting up commissioning session for already-discovered device %@ and device ID 0x%016llX with setup payload %@", discoveredDevice, newNodeID.unsignedLongLongValue, payload);
MTR_LOG("%@ Setting up commissioning session for already-discovered device %@ and device ID 0x%016llX with setup payload %@", self, discoveredDevice, newNodeID.unsignedLongLongValue, payload);

[[MTRMetricsCollector sharedInstance] resetMetrics];

Expand Down Expand Up @@ -965,8 +974,7 @@ - (MTRBaseDevice *)deviceBeingCommissionedWithNodeID:(NSNumber *)nodeID error:(N
};

MTRBaseDevice * device = [self syncRunOnWorkQueueWithReturnValue:block error:error];
MTR_LOG("Getting device being commissioned with node ID 0x%016llX: %@ (error: %@)",
nodeID.unsignedLongLongValue, device, (error ? *error : nil));
MTR_LOG("%@ Getting device being commissioned with node ID 0x%016llX: %@ (error: %@)", self, nodeID.unsignedLongLongValue, device, (error ? *error : nil));
return device;
}

Expand Down Expand Up @@ -996,7 +1004,7 @@ - (MTRDevice *)_setupDeviceForNodeID:(NSNumber *)nodeID prefetchedClusterData:(N
} else if (_controllerDataStore) {
// Load persisted cluster data if they exist.
NSDictionary * clusterData = [_controllerDataStore getStoredClusterDataForNodeID:nodeID];
MTR_LOG("Loaded %lu cluster data from storage for %@", static_cast<unsigned long>(clusterData.count), deviceToReturn);
MTR_LOG("%@ Loaded %lu cluster data from storage for %@", self, static_cast<unsigned long>(clusterData.count), deviceToReturn);
if (clusterData.count) {
[deviceToReturn setPersistedClusterData:clusterData];
}
Expand Down Expand Up @@ -1035,7 +1043,7 @@ - (void)removeDevice:(MTRDevice *)device
[deviceToRemove invalidate];
[_nodeIDToDeviceMap removeObjectForKey:nodeID];
} else {
MTR_LOG_ERROR("Error: Cannot remove device %p with nodeID %llu", device, nodeID.unsignedLongLongValue);
MTR_LOG_ERROR("%@ Error: Cannot remove device %p with nodeID %llu", self, device, nodeID.unsignedLongLongValue);
}
}

Expand Down Expand Up @@ -1143,19 +1151,19 @@ - (BOOL)addServerEndpoint:(MTRServerEndpoint *)endpoint
}

if (![endpoint associateWithController:self]) {
MTR_LOG_ERROR("Failed to associate MTRServerEndpoint with MTRDeviceController");
MTR_LOG_ERROR("%@ Failed to associate MTRServerEndpoint with MTRDeviceController", self);
[_factory removeServerEndpoint:endpoint];
return NO;
}

[self asyncDispatchToMatterQueue:^() {
[self->_serverEndpoints addObject:endpoint];
[endpoint registerMatterEndpoint];
MTR_LOG("Added server endpoint %u to controller %@", static_cast<chip::EndpointId>(endpoint.endpointID.unsignedLongLongValue),
MTR_LOG("%@ Added server endpoint %u to controller %@", self, static_cast<chip::EndpointId>(endpoint.endpointID.unsignedLongLongValue),
self->_uniqueIdentifier);
}
errorHandler:^(NSError * error) {
MTR_LOG_ERROR("Unexpected failure dispatching to Matter queue on running controller in addServerEndpoint, adding endpoint %u",
MTR_LOG_ERROR("%@ Unexpected failure dispatching to Matter queue on running controller in addServerEndpoint, adding endpoint %u", self,
static_cast<chip::EndpointId>(endpoint.endpointID.unsignedLongLongValue));
}];
return YES;
Expand All @@ -1179,15 +1187,15 @@ - (void)removeServerEndpointInternal:(MTRServerEndpoint *)endpoint queue:(dispat
// tearing it down.
[self asyncDispatchToMatterQueue:^() {
[self removeServerEndpointOnMatterQueue:endpoint];
MTR_LOG("Removed server endpoint %u from controller %@", static_cast<chip::EndpointId>(endpoint.endpointID.unsignedLongLongValue),
MTR_LOG("%@ Removed server endpoint %u from controller %@", self, static_cast<chip::EndpointId>(endpoint.endpointID.unsignedLongLongValue),
self->_uniqueIdentifier);
if (queue != nil && completion != nil) {
dispatch_async(queue, completion);
}
}
errorHandler:^(NSError * error) {
// Error means we got shut down, so the endpoint is removed now.
MTR_LOG("controller %@ already shut down, so endpoint %u has already been removed", self->_uniqueIdentifier,
MTR_LOG("%@ controller already shut down, so endpoint %u has already been removed", self,
static_cast<chip::EndpointId>(endpoint.endpointID.unsignedLongLongValue));
if (queue != nil && completion != nil) {
dispatch_async(queue, completion);
Expand All @@ -1212,7 +1220,7 @@ - (BOOL)checkForInitError:(BOOL)condition logMsg:(NSString *)logMsg
return NO;
}

MTR_LOG_ERROR("Error: %@", logMsg);
MTR_LOG_ERROR("%@ Error: %@", self, logMsg);

[self cleanup];

Expand All @@ -1233,7 +1241,7 @@ - (BOOL)checkForStartError:(CHIP_ERROR)errorCode logMsg:(NSString *)logMsg
return NO;
}

MTR_LOG_ERROR("Error(%" CHIP_ERROR_FORMAT "): %@", errorCode.Format(), logMsg);
MTR_LOG_ERROR("%@ Error(%" CHIP_ERROR_FORMAT "): %@", self, errorCode.Format(), logMsg);

return YES;
}
Expand All @@ -1244,7 +1252,7 @@ + (BOOL)checkForError:(CHIP_ERROR)errorCode logMsg:(NSString *)logMsg error:(NSE
return NO;
}

MTR_LOG_ERROR("Error(%" CHIP_ERROR_FORMAT "): %s", errorCode.Format(), [logMsg UTF8String]);
MTR_LOG_ERROR("%@ Error(%" CHIP_ERROR_FORMAT "): %s", self, errorCode.Format(), [logMsg UTF8String]);
if (error) {
*error = [MTRError errorForCHIPErrorCode:errorCode];
}
Expand Down Expand Up @@ -1882,7 +1890,7 @@ - (MTRBaseDevice *)getDeviceBeingCommissioned:(uint64_t)deviceId error:(NSError
- (BOOL)openPairingWindow:(uint64_t)deviceID duration:(NSUInteger)duration error:(NSError * __autoreleasing *)error
{
if (duration > UINT16_MAX) {
MTR_LOG_ERROR("Error: Duration %lu is too large. Max value %d", static_cast<unsigned long>(duration), UINT16_MAX);
MTR_LOG_ERROR("%@ Error: Duration %lu is too large. Max value %d", self, static_cast<unsigned long>(duration), UINT16_MAX);
if (error) {
*error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INVALID_INTEGER_VALUE];
}
Expand All @@ -1908,15 +1916,15 @@ - (NSString *)openPairingWindowWithPIN:(uint64_t)deviceID
error:(NSError * __autoreleasing *)error
{
if (duration > UINT16_MAX) {
MTR_LOG_ERROR("Error: Duration %lu is too large. Max value %d", static_cast<unsigned long>(duration), UINT16_MAX);
MTR_LOG_ERROR("%@ Error: Duration %lu is too large. Max value %d", self, static_cast<unsigned long>(duration), UINT16_MAX);
if (error) {
*error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INVALID_INTEGER_VALUE];
}
return nil;
}

if (discriminator > 0xfff) {
MTR_LOG_ERROR("Error: Discriminator %lu is too large. Max value %d", static_cast<unsigned long>(discriminator), 0xfff);
MTR_LOG_ERROR("%@ Error: Discriminator %lu is too large. Max value %d", self, static_cast<unsigned long>(discriminator), 0xfff);
if (error) {
*error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INVALID_INTEGER_VALUE];
}
Expand All @@ -1927,7 +1935,7 @@ - (NSString *)openPairingWindowWithPIN:(uint64_t)deviceID
MATTER_LOG_METRIC_SCOPE(kMetricOpenPairingWindow, errorCode);

if (!chip::CanCastTo<uint32_t>(setupPIN) || !chip::SetupPayload::IsValidSetupPIN(static_cast<uint32_t>(setupPIN))) {
MTR_LOG_ERROR("Error: Setup pin %lu is not valid", static_cast<unsigned long>(setupPIN));
MTR_LOG_ERROR("%@ Error: Setup pin %lu is not valid", self, static_cast<unsigned long>(setupPIN));
errorCode = CHIP_ERROR_INVALID_INTEGER_VALUE;
if (error) {
*error = [MTRError errorForCHIPErrorCode:errorCode];
Expand All @@ -1949,11 +1957,11 @@ - (NSString *)openPairingWindowWithPIN:(uint64_t)deviceID
std::string outCode;

if (CHIP_NO_ERROR != (errorCode = generator.payloadDecimalStringRepresentation(outCode))) {
MTR_LOG_ERROR("Failed to get decimal setup code");
MTR_LOG_ERROR("%@ Failed to get decimal setup code", self);
return nil;
}

MTR_LOG_ERROR("Setup code is %s", outCode.c_str());
MTR_LOG_ERROR("%@ Setup code is %s", self, outCode.c_str());
return [NSString stringWithCString:outCode.c_str() encoding:[NSString defaultCStringEncoding]];
};

Expand Down
Loading

0 comments on commit f6358cd

Please sign in to comment.