From 1125342d559bb465f923ad48c9947cf7687c4bb4 Mon Sep 17 00:00:00 2001 From: Jeff Tung <100387939+jtung-apple@users.noreply.github.com> Date: Thu, 23 May 2024 19:19:17 -0700 Subject: [PATCH] [Darwin] MTRDevice should throttle writes to the attribute storage (#33535) * [Darwin] MTRDevice should throttle writes to the attribute storage * Tune unit test timing to avoid race condition that fails the test when the machine is slow * Additional tuning of unit test timing to avoid timing conditions that fails the test when the machine is slow * Tune base delay to 3 seconds, to account for slow testing machines * Fix unit test * Unit test timing fix and remove debug logging * Fix TSAN issue with test values in unit test --- src/darwin/Framework/CHIP/MTRDevice.mm | 313 ++++++++++++++++-- .../Framework/CHIP/MTRDeviceController.mm | 7 + .../CHIP/MTRDeviceControllerFactory.mm | 5 +- .../CHIP/MTRDeviceControllerParameters.h | 8 + .../CHIP/MTRDeviceController_Internal.h | 4 +- .../MTRDeviceStorageBehaviorConfiguration.h | 98 ++++++ .../MTRDeviceStorageBehaviorConfiguration.mm | 105 ++++++ ...iceStorageBehaviorConfiguration_Internal.h | 21 ++ .../Framework/CHIP/MTRDevice_Internal.h | 3 + src/darwin/Framework/CHIP/Matter.h | 1 + .../Framework/CHIPTests/MTRDeviceTests.m | 243 +++++++++++++- .../CHIPTests/MTRPerControllerStorageTests.m | 134 ++++++-- .../TestHelpers/MTRDeviceTestDelegate.h | 5 + .../TestHelpers/MTRDeviceTestDelegate.m | 16 + .../TestHelpers/MTRTestDeclarations.h | 8 + .../Matter.xcodeproj/project.pbxproj | 10 + 16 files changed, 929 insertions(+), 52 deletions(-) create mode 100644 src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration.h create mode 100644 src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration.mm create mode 100644 src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration_Internal.h diff --git a/src/darwin/Framework/CHIP/MTRDevice.mm b/src/darwin/Framework/CHIP/MTRDevice.mm index 01f56756942b16..8d1fc08f2ee8cb 100644 --- a/src/darwin/Framework/CHIP/MTRDevice.mm +++ b/src/darwin/Framework/CHIP/MTRDevice.mm @@ -360,6 +360,7 @@ - (BOOL)unitTestForceAttributeReportsIfMatchingCache:(MTRDevice *)device; - (BOOL)unitTestPretendThreadEnabled:(MTRDevice *)device; - (void)unitTestSubscriptionPoolDequeue:(MTRDevice *)device; - (void)unitTestSubscriptionPoolWorkComplete:(MTRDevice *)device; +- (void)unitTestClusterDataPersisted:(MTRDevice *)device; @end #endif @@ -400,6 +401,23 @@ @implementation MTRDevice { // Tracking of initial subscribe latency. When _initialSubscribeStart is // nil, we are not tracking the latency. NSDate * _Nullable _initialSubscribeStart; + + // Storage behavior configuration and variables to keep track of the logic + // _clusterDataPersistenceFirstScheduledTime is used to track the start time of the delay between + // report and persistence. + // _mostRecentReportTimes is a list of the most recent report timestamps used for calculating + // the running average time between reports. + // _deviceReportingExcessivelyStartTime tracks when a device starts reporting excessively. + // _reportToPersistenceDelayCurrentMultiplier is the current multiplier that is calculated when a + // report comes in. + MTRDeviceStorageBehaviorConfiguration * _storageBehaviorConfiguration; + NSDate * _Nullable _clusterDataPersistenceFirstScheduledTime; + NSMutableArray * _mostRecentReportTimes; + NSDate * _Nullable _deviceReportingExcessivelyStartTime; + double _reportToPersistenceDelayCurrentMultiplier; + + // System time change observer reference + id _systemTimeChangeObserverToken; } - (instancetype)initWithNodeID:(NSNumber *)nodeID controller:(MTRDeviceController *)controller @@ -423,11 +441,27 @@ - (instancetype)initWithNodeID:(NSNumber *)nodeID controller:(MTRDeviceControlle } _clusterDataToPersist = nil; _persistedClusters = [NSMutableSet set]; + + // If there is a data store, make sure we have an observer to + if (_persistedClusterData) { + mtr_weakify(self); + _systemTimeChangeObserverToken = [[NSNotificationCenter defaultCenter] addObserverForName:NSSystemClockDidChangeNotification object:nil queue:nil usingBlock:^(NSNotification * _Nonnull notification) { + mtr_strongify(self); + std::lock_guard lock(self->_lock); + [self _resetStorageBehaviorState]; + }]; + } + MTR_LOG_DEBUG("%@ init with hex nodeID 0x%016llX", self, _nodeID.unsignedLongLongValue); } return self; } +- (void)dealloc +{ + [[NSNotificationCenter defaultCenter] removeObserver:_systemTimeChangeObserverToken]; +} + - (NSString *)description { return [NSString @@ -1280,6 +1314,254 @@ - (void)_handleReportBegin return clusterDataToReturn; } +- (NSTimeInterval)_reportToPersistenceDelayTimeAfterMutiplier +{ + return _storageBehaviorConfiguration.reportToPersistenceDelayTime * _reportToPersistenceDelayCurrentMultiplier; +} + +- (NSTimeInterval)_reportToPersistenceDelayTimeMaxAfterMutiplier +{ + return _storageBehaviorConfiguration.reportToPersistenceDelayTimeMax * _reportToPersistenceDelayCurrentMultiplier; +} + +- (BOOL)_dataStoreExists +{ + os_unfair_lock_assert_owner(&self->_lock); + return _persistedClusterData != nil; +} + +- (void)_persistClusterData +{ + os_unfair_lock_assert_owner(&self->_lock); + + // Nothing to persist + if (!_clusterDataToPersist.count) { + return; + } + + MTR_LOG("%@ Storing cluster information (data version and attributes) count: %lu", self, static_cast(_clusterDataToPersist.count)); + // We're going to hand out these MTRDeviceClusterData objects to our + // storage implementation, which will try to read them later. Make sure + // we snapshot the state here instead of handing out live copies. + NSDictionary * clusterData = [self _clusterDataToPersistSnapshot]; + [_deviceController.controllerDataStore storeClusterData:clusterData forNodeID:_nodeID]; + for (MTRClusterPath * clusterPath in _clusterDataToPersist) { + [_persistedClusterData setObject:_clusterDataToPersist[clusterPath] forKey:clusterPath]; + [_persistedClusters addObject:clusterPath]; + } + + // TODO: There is one edge case not handled well here: if the + // storeClusterData call above fails somehow, and then the data gets + // evicted from _persistedClusterData, we could end up in a situation + // where when we page things in from storage we have stale values and + // hence effectively lose the delta that we failed to persist. + // + // The only way to handle this would be to detect it when it happens, + // then re-subscribe at that point, which would cause the relevant data + // to be sent to us via the priming read. + _clusterDataToPersist = nil; + +#ifdef DEBUG + id delegate = _weakDelegate.strongObject; + if (delegate) { + dispatch_async(_delegateQueue, ^{ + if ([delegate respondsToSelector:@selector(unitTestClusterDataPersisted:)]) { + [delegate unitTestClusterDataPersisted:self]; + } + }); + } +#endif +} + +- (BOOL)_deviceIsReportingExcessively +{ + os_unfair_lock_assert_owner(&self->_lock); + + if (!_deviceReportingExcessivelyStartTime) { + return NO; + } + + NSTimeInterval intervalSinceDeviceReportingExcessively = -[_deviceReportingExcessivelyStartTime timeIntervalSinceNow]; + BOOL deviceIsReportingExcessively = intervalSinceDeviceReportingExcessively > _storageBehaviorConfiguration.deviceReportingExcessivelyIntervalThreshold; + if (deviceIsReportingExcessively) { + MTR_LOG("%@ storage behavior: device has been reporting excessively for %.3lf seconds", self, intervalSinceDeviceReportingExcessively); + } + return deviceIsReportingExcessively; +} + +- (void)_persistClusterDataAsNeeded +{ + std::lock_guard lock(_lock); + + // Nothing to persist + if (!_clusterDataToPersist.count) { + return; + } + + // This is run with a dispatch_after, and need to check again if this device is reporting excessively + if ([self _deviceIsReportingExcessively]) { + return; + } + + NSDate * lastReportTime = [_mostRecentReportTimes lastObject]; + NSTimeInterval intervalSinceLastReport = -[lastReportTime timeIntervalSinceNow]; + if (intervalSinceLastReport < [self _reportToPersistenceDelayTimeAfterMutiplier]) { + // A report came in after this call was scheduled + + if (!_clusterDataPersistenceFirstScheduledTime) { + MTR_LOG_ERROR("%@ storage behavior: expects _clusterDataPersistenceFirstScheduledTime if _clusterDataToPersist exists", self); + return; + } + + NSTimeInterval intervalSinceFirstScheduledPersistence = -[_clusterDataPersistenceFirstScheduledTime timeIntervalSinceNow]; + if (intervalSinceFirstScheduledPersistence < [self _reportToPersistenceDelayTimeMaxAfterMutiplier]) { + MTR_LOG("%@ storage behavior: not persisting: intervalSinceLastReport %lf intervalSinceFirstScheduledPersistence %lf", self, intervalSinceLastReport, intervalSinceFirstScheduledPersistence); + // The max delay is also not reached - do not persist yet + return; + } + } + + // At this point, there is data to persist, and either _reportToPersistenceDelayTime was + // reached, or _reportToPersistenceDelayTimeMax was reached. Time to persist: + [self _persistClusterData]; + + _clusterDataPersistenceFirstScheduledTime = nil; +} + +#ifdef DEBUG +- (void)unitTestSetMostRecentReportTimes:(NSMutableArray *)mostRecentReportTimes +{ + _mostRecentReportTimes = mostRecentReportTimes; +} +#endif + +- (void)_scheduleClusterDataPersistence +{ + os_unfair_lock_assert_owner(&self->_lock); + + // No persisted data / lack of controller data store + if (![self _dataStoreExists]) { + MTR_LOG_DEBUG("%@ storage behavior: no data store", self); + return; + } + + // Nothing to persist + if (!_clusterDataToPersist.count) { + MTR_LOG_DEBUG("%@ storage behavior: nothing to persist", self); + return; + } + + // If there is no storage behavior configuration, make a default one + if (!_storageBehaviorConfiguration) { + _storageBehaviorConfiguration = [[MTRDeviceStorageBehaviorConfiguration alloc] init]; + [_storageBehaviorConfiguration checkValuesAndResetToDefaultIfNecessary]; + } + + // Directly store if the storage behavior optimization is disabled + if (_storageBehaviorConfiguration.disableStorageBehaviorOptimization) { + [self _persistClusterData]; + return; + } + + // Ensure there is an array to keep the most recent report times + if (!_mostRecentReportTimes) { + _mostRecentReportTimes = [NSMutableArray array]; + } + + // Mark when first report comes in to know when _reportToPersistenceDelayTimeMax is hit + if (!_clusterDataPersistenceFirstScheduledTime) { + _clusterDataPersistenceFirstScheduledTime = [NSDate now]; + } + + // Make sure there is space in the array, and note report time + while (_mostRecentReportTimes.count >= _storageBehaviorConfiguration.recentReportTimesMaxCount) { + [_mostRecentReportTimes removeObjectAtIndex:0]; + } + [_mostRecentReportTimes addObject:[NSDate now]]; + + // Calculate running average and update multiplier - need at least 2 items to calculate intervals + if (_mostRecentReportTimes.count > 2) { + NSTimeInterval cumulativeIntervals = 0; + for (int i = 1; i < _mostRecentReportTimes.count; i++) { + NSDate * lastDate = [_mostRecentReportTimes objectAtIndex:i - 1]; + NSDate * currentDate = [_mostRecentReportTimes objectAtIndex:i]; + NSTimeInterval intervalSinceLastReport = [currentDate timeIntervalSinceDate:lastDate]; + // Check to guard against clock change + if (intervalSinceLastReport > 0) { + cumulativeIntervals += intervalSinceLastReport; + } + } + NSTimeInterval averageTimeBetweenReports = cumulativeIntervals / (_mostRecentReportTimes.count - 1); + + if (averageTimeBetweenReports < _storageBehaviorConfiguration.timeBetweenReportsTooShortThreshold) { + // Multiplier goes from 1 to _reportToPersistenceDelayMaxMultiplier uniformly, as + // averageTimeBetweenReports go from timeBetweenReportsTooShortThreshold to + // timeBetweenReportsTooShortMinThreshold + + double intervalAmountBelowThreshold = _storageBehaviorConfiguration.timeBetweenReportsTooShortThreshold - averageTimeBetweenReports; + double intervalAmountBetweenThresholdAndMinThreshold = _storageBehaviorConfiguration.timeBetweenReportsTooShortThreshold - _storageBehaviorConfiguration.timeBetweenReportsTooShortMinThreshold; + double proportionTowardMinThreshold = intervalAmountBelowThreshold / intervalAmountBetweenThresholdAndMinThreshold; + if (proportionTowardMinThreshold > 1) { + // Clamp to 100% + proportionTowardMinThreshold = 1; + } + + // Set current multiplier to [1, MaxMultiplier] + _reportToPersistenceDelayCurrentMultiplier = 1 + (proportionTowardMinThreshold * (_storageBehaviorConfiguration.reportToPersistenceDelayMaxMultiplier - 1)); + MTR_LOG("%@ storage behavior: device reporting frequently - setting delay multiplied to %lf", self, _reportToPersistenceDelayCurrentMultiplier); + } else { + _reportToPersistenceDelayCurrentMultiplier = 1; + } + + // Also note when the running average first dips below the min threshold + if (averageTimeBetweenReports < _storageBehaviorConfiguration.timeBetweenReportsTooShortMinThreshold) { + if (!_deviceReportingExcessivelyStartTime) { + _deviceReportingExcessivelyStartTime = [NSDate now]; + MTR_LOG_DEBUG("%@ storage behavior: device is reporting excessively @%@", self, _deviceReportingExcessivelyStartTime); + } + } else { + _deviceReportingExcessivelyStartTime = nil; + } + } + + // Do not schedule persistence if device is reporting excessively + if ([self _deviceIsReportingExcessively]) { + return; + } + + dispatch_after(dispatch_time(DISPATCH_TIME_NOW, (int64_t) ([self _reportToPersistenceDelayTimeAfterMutiplier] * NSEC_PER_SEC)), self.queue, ^{ + [self _persistClusterDataAsNeeded]; + }); +} + +// Used to clear the storage behavior state when needed (system time change, or when new +// configuration is set. +// +// Also flushes unwritten cluster data to storage, if data store exists. +- (void)_resetStorageBehaviorState +{ + os_unfair_lock_assert_owner(&self->_lock); + + _clusterDataPersistenceFirstScheduledTime = nil; + _mostRecentReportTimes = nil; + _deviceReportingExcessivelyStartTime = nil; + _reportToPersistenceDelayCurrentMultiplier = 1; + + if (_persistedClusters) { + [self _persistClusterData]; + } +} + +- (void)setStorageBehaviorConfiguration:(MTRDeviceStorageBehaviorConfiguration *)storageBehaviorConfiguration +{ + MTR_LOG("%@ storage behavior: setStorageBehaviorConfiguration %@", self, storageBehaviorConfiguration); + std::lock_guard lock(_lock); + _storageBehaviorConfiguration = storageBehaviorConfiguration; + // Make sure the values are sane + [_storageBehaviorConfiguration checkValuesAndResetToDefaultIfNecessary]; + [self _resetStorageBehaviorState]; +} + - (void)_handleReportEnd { std::lock_guard lock(_lock); @@ -1287,30 +1569,7 @@ - (void)_handleReportEnd _receivingPrimingReport = NO; _estimatedStartTimeFromGeneralDiagnosticsUpTime = nil; - BOOL dataStoreExists = _deviceController.controllerDataStore != nil; - if (dataStoreExists && _clusterDataToPersist != nil && _clusterDataToPersist.count) { - MTR_LOG("%@ Storing cluster information (data version and attributes) count: %lu", self, static_cast(_clusterDataToPersist.count)); - // We're going to hand out these MTRDeviceClusterData objects to our - // storage implementation, which will try to read them later. Make sure - // we snapshot the state here instead of handing out live copies. - NSDictionary * clusterData = [self _clusterDataToPersistSnapshot]; - [_deviceController.controllerDataStore storeClusterData:clusterData forNodeID:_nodeID]; - for (MTRClusterPath * clusterPath in _clusterDataToPersist) { - [_persistedClusterData setObject:_clusterDataToPersist[clusterPath] forKey:clusterPath]; - [_persistedClusters addObject:clusterPath]; - } - - // TODO: There is one edge case not handled well here: if the - // storeClusterData call above fails somehow, and then the data gets - // evicted from _persistedClusterData, we could end up in a situation - // where when we page things in from storage we have stale values and - // hence effectively lose the delta that we failed to persist. - // - // The only way to handle this would be to detect it when it happens, - // then re-subscribe at that point, which would cause the relevant data - // to be sent to us via the priming read. - _clusterDataToPersist = nil; - } + [self _scheduleClusterDataPersistence]; // After the handling of the report, if we detected a device configuration change, notify the delegate // of the same. @@ -1480,7 +1739,7 @@ - (void)_handleEventReport:(NSArray *> *)eventRepor - (void)unitTestClearClusterData { std::lock_guard lock(_lock); - NSAssert(_persistedClusterData != nil, @"Test is not going to test what it thinks is testing!"); + NSAssert([self _dataStoreExists], @"Test is not going to test what it thinks is testing!"); [_persistedClusterData removeAllObjects]; } #endif @@ -1497,7 +1756,7 @@ - (nullable MTRDeviceClusterData *)_clusterDataForPath:(MTRClusterPath *)cluster } } - if (_persistedClusterData != nil) { + if ([self _dataStoreExists]) { MTRDeviceClusterData * data = [_persistedClusterData objectForKey:clusterPath]; if (data != nil) { return data; @@ -2878,7 +3137,7 @@ - (void)setPersistedClusterData:(NSDictionary * _serverEndpoints; + + MTRDeviceStorageBehaviorConfiguration * _storageBehaviorConfiguration; } - (nullable instancetype)initWithParameters:(MTRDeviceControllerAbstractParameters *)parameters error:(NSError * __autoreleasing *)error @@ -153,6 +155,7 @@ - (instancetype)initWithFactory:(MTRDeviceControllerFactory *)factory otaProviderDelegateQueue:(dispatch_queue_t _Nullable)otaProviderDelegateQueue uniqueIdentifier:(NSUUID *)uniqueIdentifier concurrentSubscriptionPoolSize:(NSUInteger)concurrentSubscriptionPoolSize + storageBehaviorConfiguration:(MTRDeviceStorageBehaviorConfiguration *)storageBehaviorConfiguration { if (self = [super init]) { // Make sure our storage is all set up to work as early as possible, @@ -274,6 +277,8 @@ - (instancetype)initWithFactory:(MTRDeviceControllerFactory *)factory _concurrentSubscriptionPool = [[MTRAsyncWorkQueue alloc] initWithContext:self width:concurrentSubscriptionPoolSize]; _storedFabricIndex = chip::kUndefinedFabricIndex; + + _storageBehaviorConfiguration = storageBehaviorConfiguration; } return self; } @@ -989,6 +994,8 @@ - (MTRDevice *)_setupDeviceForNodeID:(NSNumber *)nodeID prefetchedClusterData:(N } } + [deviceToReturn setStorageBehaviorConfiguration:_storageBehaviorConfiguration]; + return deviceToReturn; } diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerFactory.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerFactory.mm index 53bf36e8a6e70c..662a228bdd994e 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerFactory.mm +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerFactory.mm @@ -473,6 +473,7 @@ - (MTRDeviceController * _Nullable)_startDeviceController:(MTRDeviceController * id _Nullable otaProviderDelegate; dispatch_queue_t _Nullable otaProviderDelegateQueue; NSUInteger concurrentSubscriptionPoolSize = 0; + MTRDeviceStorageBehaviorConfiguration * storageBehaviorConfiguration = nil; if ([startupParams isKindOfClass:[MTRDeviceControllerParameters class]]) { MTRDeviceControllerParameters * params = startupParams; storageDelegate = params.storageDelegate; @@ -481,6 +482,7 @@ - (MTRDeviceController * _Nullable)_startDeviceController:(MTRDeviceController * otaProviderDelegate = params.otaProviderDelegate; otaProviderDelegateQueue = params.otaProviderDelegateQueue; concurrentSubscriptionPoolSize = params.concurrentSubscriptionEstablishmentsAllowedOnThread; + storageBehaviorConfiguration = params.storageBehaviorConfiguration; } else if ([startupParams isKindOfClass:[MTRDeviceControllerStartupParams class]]) { MTRDeviceControllerStartupParams * params = startupParams; storageDelegate = nil; @@ -542,7 +544,8 @@ - (MTRDeviceController * _Nullable)_startDeviceController:(MTRDeviceController * otaProviderDelegate:otaProviderDelegate otaProviderDelegateQueue:otaProviderDelegateQueue uniqueIdentifier:uniqueIdentifier - concurrentSubscriptionPoolSize:concurrentSubscriptionPoolSize]; + concurrentSubscriptionPoolSize:concurrentSubscriptionPoolSize + storageBehaviorConfiguration:storageBehaviorConfiguration]; if (controller == nil) { if (error != nil) { *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INVALID_ARGUMENT]; diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerParameters.h b/src/darwin/Framework/CHIP/MTRDeviceControllerParameters.h index d42032cad57dd2..548f1c64714f80 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerParameters.h +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerParameters.h @@ -17,6 +17,7 @@ #import #import +#import #import NS_ASSUME_NONNULL_BEGIN @@ -85,6 +86,13 @@ MTR_AVAILABLE(ios(17.6), macos(14.6), watchos(10.6), tvos(17.6)) */ @property (nonatomic, assign) NSUInteger concurrentSubscriptionEstablishmentsAllowedOnThread MTR_NEWLY_AVAILABLE; +/** + * Sets the storage behavior configuration - see MTRDeviceStorageBehaviorConfiguration.h for details + * + * If this value is nil, a default storage behavior configuration will be used. + */ +@property (nonatomic, copy, nullable) MTRDeviceStorageBehaviorConfiguration * storageBehaviorConfiguration; + @end MTR_AVAILABLE(ios(17.6), macos(14.6), watchos(10.6), tvos(17.6)) diff --git a/src/darwin/Framework/CHIP/MTRDeviceController_Internal.h b/src/darwin/Framework/CHIP/MTRDeviceController_Internal.h index 8aefa481ba7616..8fb61fba9bab80 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceController_Internal.h +++ b/src/darwin/Framework/CHIP/MTRDeviceController_Internal.h @@ -32,6 +32,7 @@ #import "MTRBaseDevice.h" #import "MTRDeviceController.h" #import "MTRDeviceControllerDataStore.h" +#import "MTRDeviceStorageBehaviorConfiguration.h" #import #import @@ -113,7 +114,8 @@ NS_ASSUME_NONNULL_BEGIN otaProviderDelegate:(id _Nullable)otaProviderDelegate otaProviderDelegateQueue:(dispatch_queue_t _Nullable)otaProviderDelegateQueue uniqueIdentifier:(NSUUID *)uniqueIdentifier - concurrentSubscriptionPoolSize:(NSUInteger)concurrentSubscriptionPoolSize; + concurrentSubscriptionPoolSize:(NSUInteger)concurrentSubscriptionPoolSize + storageBehaviorConfiguration:(MTRDeviceStorageBehaviorConfiguration *)storageBehaviorConfiguration; /** * Check whether this controller is running on the given fabric, as represented diff --git a/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration.h b/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration.h new file mode 100644 index 00000000000000..30ea957cd3987d --- /dev/null +++ b/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration.h @@ -0,0 +1,98 @@ +/** + * Copyright (c) 2024 Project CHIP Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#import +#import + +NS_ASSUME_NONNULL_BEGIN + +/** + * Class that configures how MTRDevice objects persist its attributes to storage, so as to not + * overwhelm the underlying storage system. + */ +MTR_NEWLY_AVAILABLE +@interface MTRDeviceStorageBehaviorConfiguration : NSObject + +/** + * Create configuration with a default set of values. See description below for details. + */ ++ (instancetype)configurationWithDefaultStorageBehavior; + +/** + * Create configuration that disables storage behavior optimizations. + */ ++ (instancetype)configurationWithStorageBehaviorOptimizationDisabled; + +/** + * Create configuration with specified values. See description below for details, and the list of + * properties below for valid ranges of these values. + */ ++ (instancetype)configurationWithReportToPersistenceDelayTime:(NSTimeInterval)reportToPersistenceDelayTime + reportToPersistenceDelayTimeMax:(NSTimeInterval)reportToPersistenceDelayTimeMax + recentReportTimesMaxCount:(NSUInteger)recentReportTimesMaxCount + timeBetweenReportsTooShortThreshold:(NSTimeInterval)timeBetweenReportsTooShortThreshold + timeBetweenReportsTooShortMinThreshold:(NSTimeInterval)timeBetweenReportsTooShortMinThreshold + reportToPersistenceDelayMaxMultiplier:(double)reportToPersistenceDelayMaxMultiplier + deviceReportingExcessivelyIntervalThreshold:(NSTimeInterval)deviceReportingExcessivelyIntervalThreshold; + +/** + * Storage behavior with values in the allowed range: + * + * Each time a report comes in, MTRDevice will wait reportToPersistDelayTime before persisting the + * changes to storage. If another report comes in during this internal, MTRDevice will wait another + * reportToPersistDelayTime interval, until reportToPersistDelayTimeMax is reached, at which + * point all the changes so far will be written to storage. + * + * MTRDevice will also track recentReportTimesMaxCount number of report times. If the running + * average time between reports dips below timeBetweenReportsTooShortThreshold, a portion of the + * reportToPersistenceDelayMaxMultiplier will be applied to both the reportToPersistenceDelayTime + * and reportToPersistenceDelayTimeMax. The multiplier will reach the max when the average time + * between reports reach timeBetweenReportsTooShortMinThreshold. + * + * When the running average time between reports dips below timeBetweenReportsTooShortMinThreshold + * for the first time, the time will be noted. If the device remains in this state for longer than + * deviceReportingExcessivelyIntervalThreshold, persistence will stop until the average time between + * reports go back above timeBetweenReportsTooShortMinThreshold. + */ + +/** + * If disableStorageBehaviorOptimization is set to YES, then all the waiting mechanism as described above + * is disabled. + */ +@property (nonatomic, assign) BOOL disableStorageBehaviorOptimization; + +/** + * If any of these properties are set to be out of the documented limits, these default values will + * be used to replace all of them: + * + * reportToPersistenceDelayTimeDefault (15) + * reportToPersistenceDelayTimeMaxDefault (20 * kReportToPersistenceDelayTimeDefault) + * recentReportTimesMaxCountDefault (12) + * timeBetweenReportsTooShortThresholdDefault (15) + * timeBetweenReportsTooShortMinThresholdDefault (5) + * reportToPersistenceDelayMaxMultiplierDefault (10) + * deviceReportingExcessivelyIntervalThresholdDefault (5 * 60) + */ +@property (nonatomic, assign) NSTimeInterval reportToPersistenceDelayTime; /* must be > 0 */ +@property (nonatomic, assign) NSTimeInterval reportToPersistenceDelayTimeMax; /* must be larger than reportToPersistenceDelayTime */ +@property (nonatomic, assign) NSUInteger recentReportTimesMaxCount; /* must be >= 2 */ +@property (nonatomic, assign) NSTimeInterval timeBetweenReportsTooShortThreshold; /* must be > 0 */ +@property (nonatomic, assign) NSTimeInterval timeBetweenReportsTooShortMinThreshold; /* must be > 0 and smaller than timeBetweenReportsTooShortThreshold */ +@property (nonatomic, assign) double reportToPersistenceDelayMaxMultiplier; /* must be > 1 */ +@property (nonatomic, assign) NSTimeInterval deviceReportingExcessivelyIntervalThreshold; /* must be > 0 */ +@end + +NS_ASSUME_NONNULL_END diff --git a/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration.mm b/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration.mm new file mode 100644 index 00000000000000..4522c7e69b4ad6 --- /dev/null +++ b/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration.mm @@ -0,0 +1,105 @@ +/** + * Copyright (c) 2024 Project CHIP Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#import "MTRDeviceStorageBehaviorConfiguration.h" + +#import "MTRLogging_Internal.h" + +#define kReportToPersistenceDelayTimeDefault (15) +#define kReportToPersistenceDelayTimeMaxDefault (20 * kReportToPersistenceDelayTimeDefault) +#define kRecentReportTimesMaxCountDefault (12) +#define kTimeBetweenReportsTooShortThresholdDefault (15) +#define kTimeBetweenReportsTooShortMinThresholdDefault (5) +#define kReportToPersistenceDelayMaxMultiplierDefault (10) +#define kDeviceReportingExcessivelyIntervalThresholdDefault (5 * 60) + +@implementation MTRDeviceStorageBehaviorConfiguration + ++ (instancetype)configurationWithReportToPersistenceDelayTime:(NSTimeInterval)reportToPersistenceDelayTime + reportToPersistenceDelayTimeMax:(NSTimeInterval)reportToPersistenceDelayTimeMax + recentReportTimesMaxCount:(NSUInteger)recentReportTimesMaxCount + timeBetweenReportsTooShortThreshold:(NSTimeInterval)timeBetweenReportsTooShortThreshold + timeBetweenReportsTooShortMinThreshold:(NSTimeInterval)timeBetweenReportsTooShortMinThreshold + reportToPersistenceDelayMaxMultiplier:(double)reportToPersistenceDelayMaxMultiplier + deviceReportingExcessivelyIntervalThreshold:(NSTimeInterval)deviceReportingExcessivelyIntervalThreshold +{ + auto newConfiguration = [[MTRDeviceStorageBehaviorConfiguration alloc] init]; + newConfiguration.reportToPersistenceDelayTime = reportToPersistenceDelayTime; + newConfiguration.reportToPersistenceDelayTimeMax = reportToPersistenceDelayTimeMax; + newConfiguration.recentReportTimesMaxCount = recentReportTimesMaxCount; + newConfiguration.timeBetweenReportsTooShortThreshold = timeBetweenReportsTooShortThreshold; + newConfiguration.timeBetweenReportsTooShortMinThreshold = timeBetweenReportsTooShortMinThreshold; + newConfiguration.reportToPersistenceDelayMaxMultiplier = reportToPersistenceDelayMaxMultiplier; + newConfiguration.deviceReportingExcessivelyIntervalThreshold = deviceReportingExcessivelyIntervalThreshold; + + return newConfiguration; +} + ++ (instancetype)configurationWithDefaultStorageBehavior +{ + auto newConfiguration = [[MTRDeviceStorageBehaviorConfiguration alloc] init]; + [newConfiguration checkValuesAndResetToDefaultIfNecessary]; + return newConfiguration; +} + ++ (instancetype)configurationWithStorageBehaviorOptimizationDisabled +{ + auto newConfiguration = [[MTRDeviceStorageBehaviorConfiguration alloc] init]; + newConfiguration.disableStorageBehaviorOptimization = YES; + return newConfiguration; +} + +- (NSString *)description +{ + return [NSString stringWithFormat:@"(_recentReportTimesMaxCount), _timeBetweenReportsTooShortThreshold, _timeBetweenReportsTooShortMinThreshold, _reportToPersistenceDelayMaxMultiplier, _deviceReportingExcessivelyIntervalThreshold]; +} + +- (void)checkValuesAndResetToDefaultIfNecessary +{ + if (_disableStorageBehaviorOptimization) { + return; + } + + // Sanity check all the values, and if any is out of range, reset to default values + if ((_reportToPersistenceDelayTime <= 0) || (_reportToPersistenceDelayTimeMax <= 0) || (_reportToPersistenceDelayTimeMax < _reportToPersistenceDelayTime) || (_recentReportTimesMaxCount < 2) || (_timeBetweenReportsTooShortThreshold <= 0) || (_timeBetweenReportsTooShortMinThreshold <= 0) || (_timeBetweenReportsTooShortMinThreshold > _timeBetweenReportsTooShortThreshold) || (_reportToPersistenceDelayMaxMultiplier <= 1) || (_deviceReportingExcessivelyIntervalThreshold <= 0)) { + MTR_LOG_ERROR("%@ storage behavior: MTRDeviceStorageBehaviorConfiguration values out of bounds - resetting to default", self); + + _reportToPersistenceDelayTime = kReportToPersistenceDelayTimeDefault; + _reportToPersistenceDelayTimeMax = kReportToPersistenceDelayTimeMaxDefault; + _recentReportTimesMaxCount = kRecentReportTimesMaxCountDefault; + _timeBetweenReportsTooShortThreshold = kTimeBetweenReportsTooShortThresholdDefault; + _timeBetweenReportsTooShortMinThreshold = kTimeBetweenReportsTooShortMinThresholdDefault; + _reportToPersistenceDelayMaxMultiplier = kReportToPersistenceDelayMaxMultiplierDefault; + _deviceReportingExcessivelyIntervalThreshold = kDeviceReportingExcessivelyIntervalThresholdDefault; + } +} + +- (id)copyWithZone:(NSZone *)zone +{ + auto newConfiguration = [[MTRDeviceStorageBehaviorConfiguration alloc] init]; + newConfiguration.disableStorageBehaviorOptimization = _disableStorageBehaviorOptimization; + newConfiguration.reportToPersistenceDelayTime = _reportToPersistenceDelayTime; + newConfiguration.reportToPersistenceDelayTimeMax = _reportToPersistenceDelayTimeMax; + newConfiguration.recentReportTimesMaxCount = _recentReportTimesMaxCount; + newConfiguration.timeBetweenReportsTooShortThreshold = _timeBetweenReportsTooShortThreshold; + newConfiguration.timeBetweenReportsTooShortMinThreshold = _timeBetweenReportsTooShortMinThreshold; + newConfiguration.reportToPersistenceDelayMaxMultiplier = _reportToPersistenceDelayMaxMultiplier; + newConfiguration.deviceReportingExcessivelyIntervalThreshold = _deviceReportingExcessivelyIntervalThreshold; + + return newConfiguration; +} + +@end diff --git a/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration_Internal.h b/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration_Internal.h new file mode 100644 index 00000000000000..f3c8cf992f7bbc --- /dev/null +++ b/src/darwin/Framework/CHIP/MTRDeviceStorageBehaviorConfiguration_Internal.h @@ -0,0 +1,21 @@ +/** + * Copyright (c) 2024 Project CHIP Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#import "MTRDeviceStorageBehaviorConfiguration.h" + +@interface MTRDeviceStorageBehaviorConfiguration () +- (void)checkValuesAndResetToDefaultIfNecessary; +@end diff --git a/src/darwin/Framework/CHIP/MTRDevice_Internal.h b/src/darwin/Framework/CHIP/MTRDevice_Internal.h index c479627221fda0..a9647122d4fba2 100644 --- a/src/darwin/Framework/CHIP/MTRDevice_Internal.h +++ b/src/darwin/Framework/CHIP/MTRDevice_Internal.h @@ -21,6 +21,7 @@ #import "MTRAsyncWorkQueue.h" #import "MTRDefines_Internal.h" +#import "MTRDeviceStorageBehaviorConfiguration_Internal.h" NS_ASSUME_NONNULL_BEGIN @@ -113,6 +114,8 @@ MTR_TESTABLE - (NSUInteger)unitTestAttributeCount; #endif +- (void)setStorageBehaviorConfiguration:(MTRDeviceStorageBehaviorConfiguration *)storageBehaviorConfiguration; + @end #pragma mark - Utility for clamping numbers diff --git a/src/darwin/Framework/CHIP/Matter.h b/src/darwin/Framework/CHIP/Matter.h index ebbe1b3765917c..3c0ec41443303c 100644 --- a/src/darwin/Framework/CHIP/Matter.h +++ b/src/darwin/Framework/CHIP/Matter.h @@ -47,6 +47,7 @@ #import #import #import +#import #import #import #import diff --git a/src/darwin/Framework/CHIPTests/MTRDeviceTests.m b/src/darwin/Framework/CHIPTests/MTRDeviceTests.m index 38b31569831d48..b0254fbde38ad4 100644 --- a/src/darwin/Framework/CHIPTests/MTRDeviceTests.m +++ b/src/darwin/Framework/CHIPTests/MTRDeviceTests.m @@ -26,6 +26,7 @@ #import "MTRCommandPayloadExtensions_Internal.h" #import "MTRDeviceControllerLocalTestStorage.h" +#import "MTRDeviceStorageBehaviorConfiguration.h" #import "MTRDeviceTestDelegate.h" #import "MTRDevice_Internal.h" #import "MTRErrorTestUtils.h" @@ -3023,8 +3024,21 @@ - (void)test031_MTRDeviceAttributeCacheLocalTestStorage // Get the subscription primed __auto_type * device = [MTRDevice deviceWithNodeID:@(kDeviceId) controller:sController]; + + NSTimeInterval baseTestDelayTime = 1; + MTRDeviceStorageBehaviorConfiguration * config = [MTRDeviceStorageBehaviorConfiguration + configurationWithReportToPersistenceDelayTime:baseTestDelayTime + reportToPersistenceDelayTimeMax:baseTestDelayTime * 2 + recentReportTimesMaxCount:5 + timeBetweenReportsTooShortThreshold:baseTestDelayTime * 0.4 + timeBetweenReportsTooShortMinThreshold:baseTestDelayTime * 0.2 + reportToPersistenceDelayMaxMultiplier:baseTestDelayTime * 5 + deviceReportingExcessivelyIntervalThreshold:baseTestDelayTime * 10]; + [device setStorageBehaviorConfiguration:config]; + XCTestExpectation * gotReportsExpectation = [self expectationWithDescription:@"Attribute and Event reports have been received"]; XCTestExpectation * gotDeviceCachePrimed = [self expectationWithDescription:@"Device cache primed for the first time"]; + XCTestExpectation * gotClusterDataPersisted1 = [self expectationWithDescription:@"Cluster data persisted 1"]; __auto_type * delegate = [[MTRDeviceTestDelegate alloc] init]; __weak __auto_type weakDelegate = delegate; delegate.onReportEnd = ^{ @@ -3035,9 +3049,12 @@ - (void)test031_MTRDeviceAttributeCacheLocalTestStorage delegate.onDeviceCachePrimed = ^{ [gotDeviceCachePrimed fulfill]; }; + delegate.onClusterDataPersisted = ^{ + [gotClusterDataPersisted1 fulfill]; + }; [device setDelegate:delegate queue:queue]; - [self waitForExpectations:@[ gotReportsExpectation, gotDeviceCachePrimed ] timeout:60]; + [self waitForExpectations:@[ gotReportsExpectation, gotDeviceCachePrimed, gotClusterDataPersisted1 ] timeout:60]; NSUInteger attributesReportedWithFirstSubscription = [device unitTestAttributesReportedSinceLastCheck]; @@ -3049,6 +3066,7 @@ - (void)test031_MTRDeviceAttributeCacheLocalTestStorage device = [MTRDevice deviceWithNodeID:@(kDeviceId) controller:sController]; XCTestExpectation * resubGotReportsExpectation = [self expectationWithDescription:@"Attribute and Event reports have been received for resubscription"]; + XCTestExpectation * gotClusterDataPersisted2 = [self expectationWithDescription:@"Cluster data persisted 2"]; delegate.onReportEnd = ^{ [resubGotReportsExpectation fulfill]; __strong __auto_type strongDelegate = weakDelegate; @@ -3058,9 +3076,12 @@ - (void)test031_MTRDeviceAttributeCacheLocalTestStorage delegate.onDeviceCachePrimed = ^{ onDeviceCachePrimedCalled = YES; }; + delegate.onClusterDataPersisted = ^{ + [gotClusterDataPersisted2 fulfill]; + }; [device setDelegate:delegate queue:queue]; - [self waitForExpectations:@[ resubGotReportsExpectation ] timeout:60]; + [self waitForExpectations:@[ resubGotReportsExpectation, gotClusterDataPersisted2 ] timeout:60]; // Make sure that the new callback is only ever called once, the first time subscription was primed XCTAssertFalse(onDeviceCachePrimedCalled); @@ -3647,6 +3668,224 @@ - (void)test035_TestMTRDeviceSubscriptionNotEstablishedOverXPC XCTAssertEqual([device _getInternalState], MTRInternalDeviceStateUnsubscribed); } +- (NSArray *> *)testAttributeReportWithValue:(unsigned int)testValue +{ + return @[ @{ + MTRAttributePathKey : [MTRAttributePath attributePathWithEndpointID:@(0) clusterID:@(MTRClusterIDTypeLevelControlID) attributeID:@(MTRAttributeIDTypeClusterLevelControlAttributeCurrentLevelID)], + MTRDataKey : @ { + MTRDataVersionKey : @(testValue), + MTRTypeKey : MTRUnsignedIntegerValueType, + MTRValueKey : @(testValue), + } + } ]; +} + +- (void)test036_TestStorageBehaviorConfiguration +{ + // Use separate queue for timing sensitive test + dispatch_queue_t queue = dispatch_queue_create("storage-behavior-queue", DISPATCH_QUEUE_SERIAL); + + NSDictionary * storedClusterDataAfterClear = [sController.controllerDataStore getStoredClusterDataForNodeID:@(kDeviceId)]; + XCTAssertEqual(storedClusterDataAfterClear.count, 0); + + __auto_type * device = [MTRDevice deviceWithNodeID:kDeviceId deviceController:sController]; + + __auto_type * delegate = [[MTRDeviceTestDelegateWithSubscriptionSetupOverride alloc] init]; + __block os_unfair_lock lock = OS_UNFAIR_LOCK_INIT; + __block NSDate * reportEndTime = nil; + __block NSDate * dataPersistedTime = nil; + + XCTestExpectation * dataPersisted1 = [self expectationWithDescription:@"data persisted 1"]; + delegate.onReportEnd = ^() { + os_unfair_lock_lock(&lock); + if (!reportEndTime) { + reportEndTime = [NSDate now]; + } + os_unfair_lock_unlock(&lock); + }; + + delegate.onClusterDataPersisted = ^{ + os_unfair_lock_lock(&lock); + if (!dataPersistedTime) { + dataPersistedTime = [NSDate now]; + } + os_unfair_lock_unlock(&lock); + [dataPersisted1 fulfill]; + }; + + // Do not subscribe - only inject sequence of reports to control the timing + delegate.skipSetupSubscription = YES; + + NSTimeInterval baseTestDelayTime = 3; + + // Set up a config of relatively short timers so this test doesn't take too long + MTRDeviceStorageBehaviorConfiguration * config = [MTRDeviceStorageBehaviorConfiguration + configurationWithReportToPersistenceDelayTime:baseTestDelayTime + reportToPersistenceDelayTimeMax:baseTestDelayTime * 2 + recentReportTimesMaxCount:5 + timeBetweenReportsTooShortThreshold:baseTestDelayTime * 0.4 + timeBetweenReportsTooShortMinThreshold:baseTestDelayTime * 0.2 + reportToPersistenceDelayMaxMultiplier:baseTestDelayTime * 5 + deviceReportingExcessivelyIntervalThreshold:baseTestDelayTime * 7]; + [device setStorageBehaviorConfiguration:config]; + + [device setDelegate:delegate queue:queue]; + + // Use a mutable dictionary so the data value can be easily changed between reports + unsigned int currentTestValue = 1; + + // Test 1: Inject report and see that the attribute persisted, with a delay + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + [self waitForExpectations:@[ dataPersisted1 ] timeout:60]; + + os_unfair_lock_lock(&lock); + NSTimeInterval reportToPersistenceDelay = [dataPersistedTime timeIntervalSinceDate:reportEndTime]; + os_unfair_lock_unlock(&lock); + // Check delay exists + XCTAssertGreaterThan(reportToPersistenceDelay, baseTestDelayTime / 2); + // Check delay is expectd - use base delay plus small fudge in case of CPU slowness with dispatch_after + XCTAssertLessThan(reportToPersistenceDelay, baseTestDelayTime * 1.3); + + XCTestExpectation * dataPersisted2 = [self expectationWithDescription:@"data persisted 2"]; + + delegate.onClusterDataPersisted = ^{ + os_unfair_lock_lock(&lock); + if (!dataPersistedTime) { + dataPersistedTime = [NSDate now]; + } + os_unfair_lock_unlock(&lock); + [dataPersisted2 fulfill]; + }; + + // Test 2: Inject multiple reports with delay and see that the attribute persisted eventually + reportEndTime = nil; + dataPersistedTime = nil; + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + double frequentReportMultiplier = 0.5; + usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC)); + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC)); + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC)); + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC)); + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + // At this point, the threshold for reportToPersistenceDelayTimeMax should have hit, and persistence + // should have happened with timer running down to persist again with the 5th report above. Need to + // wait for expectation and immediately clear the onClusterDataPersisted callback + + [self waitForExpectations:@[ dataPersisted2 ] timeout:60]; + + os_unfair_lock_lock(&lock); + reportToPersistenceDelay = [dataPersistedTime timeIntervalSinceDate:reportEndTime]; + os_unfair_lock_unlock(&lock); + // Check delay exists and approximately reportToPersistenceDelayTimeMax, which is base delay times 2 + XCTAssertGreaterThan(reportToPersistenceDelay, baseTestDelayTime * 2 * 0.9); + XCTAssertLessThan(reportToPersistenceDelay, baseTestDelayTime * 2 * 1.3); // larger upper limit in case machine is slow + + delegate.onClusterDataPersisted = nil; + + // sleep the base delay interval to allow the onClusterDataPersisted callback to happen. + usleep((useconds_t) (baseTestDelayTime * 1.1 * USEC_PER_SEC)); + + // Test 3: test reporting frequently, and see that the delay time increased + reportEndTime = nil; + dataPersistedTime = nil; + XCTestExpectation * dataPersisted3 = [self expectationWithDescription:@"data persisted 3"]; + delegate.onClusterDataPersisted = ^{ + os_unfair_lock_lock(&lock); + if (!dataPersistedTime) { + dataPersistedTime = [NSDate now]; + } + os_unfair_lock_unlock(&lock); + [dataPersisted3 fulfill]; + }; + + // Set report times with short delay and check that the multiplier is engaged + [device unitTestSetMostRecentReportTimes:[NSMutableArray arrayWithArray:@[ + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 0.3 * 4)], + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 0.3 * 3)], + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 0.3 * 2)], + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 0.3)], + ]]]; + + // Inject final report that makes MTRDevice recalculate delay with multiplier + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + [self waitForExpectations:@[ dataPersisted3 ] timeout:60]; + + // 0.3 is between 0.4 and 0.2, which should get us at least 50% of the multiplier. + // The multiplier is 5, which is +400% of the base delay, and so 50% of the multiplier + // is +200% of the base delay, meaning 3x the base delay. + + os_unfair_lock_lock(&lock); + reportToPersistenceDelay = [dataPersistedTime timeIntervalSinceDate:reportEndTime]; + os_unfair_lock_unlock(&lock); + // Check delay exists and at least base delay times 3 + XCTAssertGreaterThan(reportToPersistenceDelay, baseTestDelayTime * 3 * 0.9); + // upper limit at most max delay times full multiplier + extra in case machine is slow + XCTAssertLessThan(reportToPersistenceDelay, baseTestDelayTime * 2 * 5 * 1.3); + + // Test 4: test reporting excessively, and see that persistence does not happen until + // reporting frequency goes back above the threshold + reportEndTime = nil; + dataPersistedTime = nil; + XCTestExpectation * dataPersisted4 = [self expectationWithDescription:@"data persisted 4"]; + delegate.onClusterDataPersisted = ^{ + os_unfair_lock_lock(&lock); + if (!dataPersistedTime) { + dataPersistedTime = [NSDate now]; + } + os_unfair_lock_unlock(&lock); + [dataPersisted4 fulfill]; + }; + + // Set report times with short delay and check that the multiplier is engaged + [device unitTestSetMostRecentReportTimes:[NSMutableArray arrayWithArray:@[ + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 0.1 * 4)], + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 0.1 * 3)], + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 0.1 * 2)], + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 0.1)], + ]]]; + + // Inject report that makes MTRDevice detect the device is reporting excessively + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + // Now keep reporting excessively for base delay time max times max multiplier, plus a bit more + NSDate * excessiveStartTime = [NSDate now]; + for (;;) { + usleep((useconds_t) (baseTestDelayTime * 0.1 * USEC_PER_SEC)); + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + NSTimeInterval elapsed = -[excessiveStartTime timeIntervalSinceNow]; + if (elapsed > (baseTestDelayTime * 2 * 5 * 1.2)) { + break; + } + } + + // Check that persistence has not happened because it's now turned off + XCTAssertNil(dataPersistedTime); + + // Now force report times to large number, to simulate time passage + [device unitTestSetMostRecentReportTimes:[NSMutableArray arrayWithArray:@[ + [NSDate dateWithTimeIntervalSinceNow:-(baseTestDelayTime * 10)], + ]]]; + + // And inject a report to trigger MTRDevice to recalculate that this device is no longer + // reporting excessively + [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES]; + + [self waitForExpectations:@[ dataPersisted4 ] timeout:60]; + + delegate.onReportEnd = nil; + delegate.onClusterDataPersisted = nil; +} + @end @interface MTRDeviceEncoderTests : XCTestCase diff --git a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m index 1cd4b2139ce412..cc27efecd2cca7 100644 --- a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m +++ b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m @@ -19,6 +19,7 @@ #import #import "MTRDeviceControllerLocalTestStorage.h" +#import "MTRDeviceStorageBehaviorConfiguration.h" #import "MTRDeviceTestDelegate.h" #import "MTRDevice_Internal.h" #import "MTRErrorTestUtils.h" @@ -259,10 +260,12 @@ - (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)roo fabricID:(NSNumber *)fabricID nodeID:(NSNumber *)nodeID storage:(MTRTestPerControllerStorage *)storage - caseAuthenticatedTags:(nullable NSSet *)caseAuthenticatedTags + caseAuthenticatedTags:(NSSet * _Nullable)caseAuthenticatedTags error:(NSError * __autoreleasing *)error certificateIssuer: (MTRPerControllerStorageTestsCertificateIssuer * __autoreleasing *)certificateIssuer + concurrentSubscriptionPoolSize:(NSUInteger)concurrentSubscriptionPoolSize + storageBehaviorConfiguration:(MTRDeviceStorageBehaviorConfiguration * _Nullable)storageBehaviorConfiguration { XCTAssertTrue(error != NULL); @@ -307,6 +310,14 @@ - (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)roo [params setOperationalCertificateIssuer:ourCertificateIssuer queue:dispatch_get_main_queue()]; + if (concurrentSubscriptionPoolSize > 0) { + params.concurrentSubscriptionEstablishmentsAllowedOnThread = concurrentSubscriptionPoolSize; + } + + if (storageBehaviorConfiguration) { + params.storageBehaviorConfiguration = storageBehaviorConfiguration; + } + return [[MTRDeviceController alloc] initWithParameters:params error:error]; } @@ -315,9 +326,23 @@ - (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)roo fabricID:(NSNumber *)fabricID nodeID:(NSNumber *)nodeID storage:(MTRTestPerControllerStorage *)storage + caseAuthenticatedTags:(nullable NSSet *)caseAuthenticatedTags error:(NSError * __autoreleasing *)error certificateIssuer: (MTRPerControllerStorageTestsCertificateIssuer * __autoreleasing *)certificateIssuer +{ + return [self startControllerWithRootKeys:rootKeys operationalKeys:operationalKeys fabricID:fabricID nodeID:nodeID storage:storage caseAuthenticatedTags:caseAuthenticatedTags error:error certificateIssuer:certificateIssuer concurrentSubscriptionPoolSize:0 storageBehaviorConfiguration:nil]; +} + +- (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)rootKeys + operationalKeys:(MTRTestKeys *)operationalKeys + fabricID:(NSNumber *)fabricID + nodeID:(NSNumber *)nodeID + storage:(MTRTestPerControllerStorage *)storage + error:(NSError * __autoreleasing *)error + certificateIssuer: + (MTRPerControllerStorageTestsCertificateIssuer * __autoreleasing *)certificateIssuer + concurrentSubscriptionPoolSize:(NSUInteger)concurrentSubscriptionPoolSize { return [self startControllerWithRootKeys:rootKeys operationalKeys:operationalKeys @@ -326,7 +351,52 @@ - (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)roo storage:storage caseAuthenticatedTags:nil error:error - certificateIssuer:certificateIssuer]; + certificateIssuer:certificateIssuer + concurrentSubscriptionPoolSize:concurrentSubscriptionPoolSize + storageBehaviorConfiguration:nil]; +} + +- (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)rootKeys + operationalKeys:(MTRTestKeys *)operationalKeys + fabricID:(NSNumber *)fabricID + nodeID:(NSNumber *)nodeID + storage:(MTRTestPerControllerStorage *)storage + error:(NSError * __autoreleasing *)error + certificateIssuer: + (MTRPerControllerStorageTestsCertificateIssuer * __autoreleasing *)certificateIssuer + storageBehaviorConfiguration:(MTRDeviceStorageBehaviorConfiguration * _Nullable)storageBehaviorConfiguration +{ + return [self startControllerWithRootKeys:rootKeys + operationalKeys:operationalKeys + fabricID:fabricID + nodeID:nodeID + storage:storage + caseAuthenticatedTags:nil + error:error + certificateIssuer:certificateIssuer + concurrentSubscriptionPoolSize:0 + storageBehaviorConfiguration:storageBehaviorConfiguration]; +} + +- (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)rootKeys + operationalKeys:(MTRTestKeys *)operationalKeys + fabricID:(NSNumber *)fabricID + nodeID:(NSNumber *)nodeID + storage:(MTRTestPerControllerStorage *)storage + error:(NSError * __autoreleasing *)error + certificateIssuer: + (MTRPerControllerStorageTestsCertificateIssuer * __autoreleasing *)certificateIssuer +{ + return [self startControllerWithRootKeys:rootKeys + operationalKeys:operationalKeys + fabricID:fabricID + nodeID:nodeID + storage:storage + caseAuthenticatedTags:nil + error:error + certificateIssuer:certificateIssuer + concurrentSubscriptionPoolSize:0 + storageBehaviorConfiguration:nil]; } - (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)rootKeys @@ -344,7 +414,9 @@ - (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)roo storage:storage caseAuthenticatedTags:caseAuthenticatedTags error:error - certificateIssuer:nil]; + certificateIssuer:nil + concurrentSubscriptionPoolSize:0 + storageBehaviorConfiguration:nil]; } - (nullable MTRDeviceController *)startControllerWithRootKeys:(MTRTestKeys *)rootKeys @@ -1315,7 +1387,7 @@ - (void)test008_TestDataStoreDirect XCTAssertFalse([controller isRunning]); } -- (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id)storageDelegate +- (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id)storageDelegate disableStorageBehaviorOptimization:(BOOL)disableStorageBehaviorOptimization { __auto_type * factory = [MTRDeviceControllerFactory sharedInstance]; XCTAssertNotNil(factory); @@ -1334,13 +1406,18 @@ - (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id * dataStoreClusterData = [controller.controllerDataStore getStoredClusterDataForNodeID:deviceID]; for (MTRClusterPath * path in dataStoreClusterData) { @@ -1422,21 +1509,31 @@ - (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id *)mostRecentReportTimes; @end #endif diff --git a/src/darwin/Framework/Matter.xcodeproj/project.pbxproj b/src/darwin/Framework/Matter.xcodeproj/project.pbxproj index 212c859610172b..df5949868d0012 100644 --- a/src/darwin/Framework/Matter.xcodeproj/project.pbxproj +++ b/src/darwin/Framework/Matter.xcodeproj/project.pbxproj @@ -254,6 +254,8 @@ 75139A702B7FE68C00E3A919 /* MTRDeviceControllerLocalTestStorage.h in Headers */ = {isa = PBXBuildFile; fileRef = 75139A6D2B7FE5D600E3A919 /* MTRDeviceControllerLocalTestStorage.h */; settings = {ATTRIBUTES = (Private, ); }; }; 7534F12828BFF20300390851 /* MTRDeviceAttestationDelegate.mm in Sources */ = {isa = PBXBuildFile; fileRef = 7534F12628BFF20300390851 /* MTRDeviceAttestationDelegate.mm */; }; 7534F12928BFF20300390851 /* MTRDeviceAttestationDelegate_Internal.h in Headers */ = {isa = PBXBuildFile; fileRef = 7534F12728BFF20300390851 /* MTRDeviceAttestationDelegate_Internal.h */; }; + 754784652BFE65CB0089C372 /* MTRDeviceStorageBehaviorConfiguration.mm in Sources */ = {isa = PBXBuildFile; fileRef = 754784642BFE65CB0089C372 /* MTRDeviceStorageBehaviorConfiguration.mm */; }; + 754784672BFE93B00089C372 /* MTRDeviceStorageBehaviorConfiguration.h in Headers */ = {isa = PBXBuildFile; fileRef = 754784632BFE65B70089C372 /* MTRDeviceStorageBehaviorConfiguration.h */; settings = {ATTRIBUTES = (Public, ); }; }; 754F3DF427FBB94B00E60580 /* MTREventTLVValueDecoder_Internal.h in Headers */ = {isa = PBXBuildFile; fileRef = 754F3DF327FBB94B00E60580 /* MTREventTLVValueDecoder_Internal.h */; }; 7560FD1C27FBBD3F005E85B3 /* MTREventTLVValueDecoder.mm in Sources */ = {isa = PBXBuildFile; fileRef = 7560FD1B27FBBD3F005E85B3 /* MTREventTLVValueDecoder.mm */; }; 7596A83E28751220004DAE0E /* MTRBaseClusters_Internal.h in Headers */ = {isa = PBXBuildFile; fileRef = 7596A83D28751220004DAE0E /* MTRBaseClusters_Internal.h */; }; @@ -676,6 +678,9 @@ 75139A6E2B7FE5E900E3A919 /* MTRDeviceControllerLocalTestStorage.mm */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.cpp.objcpp; path = MTRDeviceControllerLocalTestStorage.mm; sourceTree = ""; }; 7534F12628BFF20300390851 /* MTRDeviceAttestationDelegate.mm */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.objcpp; path = MTRDeviceAttestationDelegate.mm; sourceTree = ""; }; 7534F12728BFF20300390851 /* MTRDeviceAttestationDelegate_Internal.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = MTRDeviceAttestationDelegate_Internal.h; sourceTree = ""; }; + 754784632BFE65B70089C372 /* MTRDeviceStorageBehaviorConfiguration.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; path = MTRDeviceStorageBehaviorConfiguration.h; sourceTree = ""; }; + 754784642BFE65CB0089C372 /* MTRDeviceStorageBehaviorConfiguration.mm */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.cpp.objcpp; path = MTRDeviceStorageBehaviorConfiguration.mm; sourceTree = ""; }; + 754784662BFE6B890089C372 /* MTRDeviceStorageBehaviorConfiguration_Internal.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; path = MTRDeviceStorageBehaviorConfiguration_Internal.h; sourceTree = ""; }; 754F3DF327FBB94B00E60580 /* MTREventTLVValueDecoder_Internal.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = MTREventTLVValueDecoder_Internal.h; sourceTree = ""; }; 7560FD1B27FBBD3F005E85B3 /* MTREventTLVValueDecoder.mm */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.objcpp; path = MTREventTLVValueDecoder.mm; sourceTree = ""; }; 7596A83D28751220004DAE0E /* MTRBaseClusters_Internal.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = MTRBaseClusters_Internal.h; sourceTree = ""; }; @@ -1330,6 +1335,9 @@ 5A6FEC9527B5983000F25F42 /* MTRDeviceControllerXPCConnection.mm */, 5A6FEC8B27B5609C00F25F42 /* MTRDeviceOverXPC.h */, 5A6FEC9727B5C6AF00F25F42 /* MTRDeviceOverXPC.mm */, + 754784632BFE65B70089C372 /* MTRDeviceStorageBehaviorConfiguration.h */, + 754784662BFE6B890089C372 /* MTRDeviceStorageBehaviorConfiguration_Internal.h */, + 754784642BFE65CB0089C372 /* MTRDeviceStorageBehaviorConfiguration.mm */, 51F522692AE70761000C4050 /* MTRDeviceTypeMetadata.h */, 5129BCFC26A9EE3300122DDF /* MTRError.h */, B2E0D7AB245B0B5C003C5B48 /* MTRError_Internal.h */, @@ -1593,6 +1601,7 @@ 7596A85728788557004DAE0E /* MTRClusters.h in Headers */, 99D466E12798936D0089A18F /* MTRCommissioningParameters.h in Headers */, 75B3269C2BCDB9D600E17C4E /* MTRDeviceConnectivityMonitor.h in Headers */, + 754784672BFE93B00089C372 /* MTRDeviceStorageBehaviorConfiguration.h in Headers */, 5136661528067D550025EDAE /* MTRDeviceControllerFactory_Internal.h in Headers */, 515C1C70284F9FFB00A48F0C /* MTRFramework.h in Headers */, 7534F12928BFF20300390851 /* MTRDeviceAttestationDelegate_Internal.h in Headers */, @@ -1979,6 +1988,7 @@ B289D4222639C0D300D4E314 /* MTROnboardingPayloadParser.mm in Sources */, 3CF134AD289D8E570017A19E /* MTRDeviceAttestationInfo.mm in Sources */, 2C1B027A2641DB4E00780EF1 /* MTROperationalCredentialsDelegate.mm in Sources */, + 754784652BFE65CB0089C372 /* MTRDeviceStorageBehaviorConfiguration.mm in Sources */, 7560FD1C27FBBD3F005E85B3 /* MTREventTLVValueDecoder.mm in Sources */, 5178E67E2AE098210069DF72 /* MTRCommandTimedCheck.mm in Sources */, 7596A84928762783004DAE0E /* MTRAsyncCallbackWorkQueue.mm in Sources */,