Fix up guarantees around the "device cache primed" notification. (#33600)
We should be dispatching this only if we did not previously have a primed device
cache.
testAttributeReportWithValue was renamed, because methods starting with "test"
are run as actual tests, and that's not what it's supposed to be doing.
diff --git a/src/darwin/Framework/CHIP/MTRDevice.mm b/src/darwin/Framework/CHIP/MTRDevice.mm
index ffb0a56..4e916d1 100644
--- a/src/darwin/Framework/CHIP/MTRDevice.mm
+++ b/src/darwin/Framework/CHIP/MTRDevice.mm
@@ -376,7 +376,11 @@
#ifdef DEBUG
NSUInteger _unitTestAttributesReportedSinceLastCheck;
#endif
- BOOL _delegateDeviceCachePrimedCalled;
+
+ // _deviceCachePrimed is true if we have the data that comes from an initial
+ // subscription priming report (whether it came from storage or from our
+ // subscription).
+ BOOL _deviceCachePrimed;
// _persistedClusterData stores data that we have already persisted (when we have
// cluster data persistence enabled). Nil when we have no persistence enabled.
@@ -736,11 +740,6 @@
_weakDelegate = [MTRWeakReference weakReferenceWithObject:delegate];
_delegateQueue = queue;
- // If Check if cache is already primed and client hasn't been informed yet, call the -deviceCachePrimed: callback
- if (!_delegateDeviceCachePrimedCalled && [self _isCachePrimedWithInitialConfigurationData]) {
- [self _callDelegateDeviceCachePrimed];
- }
-
if (setUpSubscription) {
_initialSubscribeStart = [NSDate now];
if ([self _deviceUsesThread]) {
@@ -915,7 +914,7 @@
- (void)_callDelegateDeviceCachePrimed
{
os_unfair_lock_assert_owner(&self->_lock);
- _delegateDeviceCachePrimedCalled = [self _callDelegateWithBlock:^(id<MTRDeviceDelegate> delegate) {
+ [self _callDelegateWithBlock:^(id<MTRDeviceDelegate> delegate) {
if ([delegate respondsToSelector:@selector(deviceCachePrimed:)]) {
[delegate deviceCachePrimed:self];
}
@@ -994,11 +993,6 @@
[self _changeInternalState:MTRInternalDeviceStateInitialSubscriptionEstablished];
}
- // As subscription is established, check if the delegate needs to be informed
- if (!_delegateDeviceCachePrimedCalled) {
- [self _callDelegateDeviceCachePrimed];
- }
-
[self _changeState:MTRDeviceStateReachable];
// No need to monitor connectivity after subscription establishment
@@ -1480,6 +1474,13 @@
return;
}
+ // If we have nothing stored at all yet, store directly, so we move into a
+ // primed state.
+ if (!_deviceCachePrimed) {
+ [self _persistClusterData];
+ return;
+ }
+
// Ensure there is an array to keep the most recent report times
if (!_mostRecentReportTimes) {
_mostRecentReportTimes = [NSMutableArray array];
@@ -1525,7 +1526,7 @@
// 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);
+ MTR_LOG("%@ storage behavior: device reporting frequently - setting delay multiplier to %lf", self, _reportToPersistenceDelayCurrentMultiplier);
} else {
_reportToPersistenceDelayCurrentMultiplier = 1;
}
@@ -1601,6 +1602,19 @@
_deviceConfigurationChanged = NO;
}
+ // Do this after the _deviceConfigurationChanged check, so that we don't
+ // call deviceConfigurationChanged: immediately after telling our delegate
+ // we are now primed.
+ //
+ // TODO: Maybe we shouldn't dispatch deviceConfigurationChanged: for the
+ // initial priming bits?
+ if (!_deviceCachePrimed) {
+ // This is the end of the priming sequence of data reports, so we have
+ // all the data for the device now.
+ _deviceCachePrimed = YES;
+ [self _callDelegateDeviceCachePrimed];
+ }
+
// For unit testing only
#ifdef DEBUG
id delegate = _weakDelegate.strongObject;
@@ -3165,10 +3179,9 @@
[_persistedClusterData setObject:clusterData[clusterPath] forKey:clusterPath];
}
- // If cache is set from storage and is primed with initial configuration data, then assume the client had beeen informed in the past, and mark that the callback has been called
- if ([self _isCachePrimedWithInitialConfigurationData]) {
- _delegateDeviceCachePrimedCalled = YES;
- }
+ // We have some stored data. Since we don't store data until the end of the
+ // initial priming report, our device cache must be primed.
+ _deviceCachePrimed = YES;
}
- (void)_setLastInitialSubscribeLatency:(id)latency
@@ -3218,7 +3231,7 @@
- (BOOL)deviceCachePrimed
{
std::lock_guard lock(_lock);
- return [self _isCachePrimedWithInitialConfigurationData];
+ return _deviceCachePrimed;
}
// If value is non-nil, associate with expectedValueID
@@ -3395,47 +3408,6 @@
}
}
-// This method checks if there is a need to inform delegate that the attribute cache has been "primed"
-- (BOOL)_isCachePrimedWithInitialConfigurationData
-{
- os_unfair_lock_assert_owner(&self->_lock);
-
- // Check if root node descriptor exists
- MTRDeviceDataValueDictionary rootDescriptorPartsListDataValue = [self _cachedAttributeValueForPath:[MTRAttributePath attributePathWithEndpointID:@(kRootEndpointId) clusterID:@(MTRClusterIDTypeDescriptorID) attributeID:@(MTRAttributeIDTypeClusterDescriptorAttributePartsListID)]];
- if (!rootDescriptorPartsListDataValue || ![MTRArrayValueType isEqualToString:rootDescriptorPartsListDataValue[MTRTypeKey]]) {
- return NO;
- }
- NSArray * partsList = rootDescriptorPartsListDataValue[MTRValueKey];
- if (![partsList isKindOfClass:[NSArray class]] || !partsList.count) {
- MTR_LOG_ERROR("%@ unexpected type %@ for parts list %@", self, [partsList class], partsList);
- return NO;
- }
-
- // Check if we have cached descriptor clusters for each listed endpoint
- for (NSDictionary * endpointDictionary in partsList) {
- NSDictionary * endpointDataValue = endpointDictionary[MTRDataKey];
- if (![endpointDataValue isKindOfClass:[NSDictionary class]]) {
- MTR_LOG_ERROR("%@ unexpected parts list dictionary %@ data value class %@", self, endpointDictionary, [endpointDataValue class]);
- continue;
- }
- if (![MTRUnsignedIntegerValueType isEqual:endpointDataValue[MTRTypeKey]]) {
- MTR_LOG_ERROR("%@ unexpected parts list data value %@ item type %@", self, endpointDataValue, endpointDataValue[MTRTypeKey]);
- continue;
- }
- NSNumber * endpoint = endpointDataValue[MTRValueKey];
- if (![endpoint isKindOfClass:[NSNumber class]]) {
- MTR_LOG_ERROR("%@ unexpected parts list item value class %@", self, [endpoint class]);
- continue;
- }
- MTRDeviceDataValueDictionary descriptorDeviceTypeListDataValue = [self _cachedAttributeValueForPath:[MTRAttributePath attributePathWithEndpointID:endpoint clusterID:@(MTRClusterIDTypeDescriptorID) attributeID:@(MTRAttributeIDTypeClusterDescriptorAttributeDeviceTypeListID)]];
- if (![MTRArrayValueType isEqualToString:descriptorDeviceTypeListDataValue[MTRTypeKey]] || !descriptorDeviceTypeListDataValue[MTRValueKey]) {
- return NO;
- }
- }
-
- return YES;
-}
-
- (MTRBaseDevice *)newBaseDevice
{
return [MTRBaseDevice deviceWithNodeID:self.nodeID controller:self.deviceController];
diff --git a/src/darwin/Framework/CHIPTests/MTRDeviceTests.m b/src/darwin/Framework/CHIPTests/MTRDeviceTests.m
index 7a26b31..f0d6aee 100644
--- a/src/darwin/Framework/CHIPTests/MTRDeviceTests.m
+++ b/src/darwin/Framework/CHIPTests/MTRDeviceTests.m
@@ -3669,7 +3669,7 @@
XCTAssertEqual([device _getInternalState], MTRInternalDeviceStateUnsubscribed);
}
-- (NSArray<NSDictionary<NSString *, id> *> *)testAttributeReportWithValue:(unsigned int)testValue
+- (NSArray<NSDictionary<NSString *, id> *> *)_testAttributeReportWithValue:(unsigned int)testValue
{
return @[ @{
MTRAttributePathKey : [MTRAttributePath attributePathWithEndpointID:@(0) clusterID:@(MTRClusterIDTypeLevelControlID) attributeID:@(MTRAttributeIDTypeClusterLevelControlAttributeCurrentLevelID)],
@@ -3696,7 +3696,7 @@
__block NSDate * reportEndTime = nil;
__block NSDate * dataPersistedTime = nil;
- XCTestExpectation * dataPersisted1 = [self expectationWithDescription:@"data persisted 1"];
+ XCTestExpectation * dataPersistedInitial = [self expectationWithDescription:@"data persisted initial"];
delegate.onReportEnd = ^() {
os_unfair_lock_lock(&lock);
if (!reportEndTime) {
@@ -3711,7 +3711,7 @@
dataPersistedTime = [NSDate now];
}
os_unfair_lock_unlock(&lock);
- [dataPersisted1 fulfill];
+ [dataPersistedInitial fulfill];
};
// Do not subscribe - only inject sequence of reports to control the timing
@@ -3732,11 +3732,29 @@
[device setDelegate:delegate queue:queue];
- // Use a mutable dictionary so the data value can be easily changed between reports
+ // Use a counter that will be incremented for each report as the value.
unsigned int currentTestValue = 1;
+ // Initial setup: Inject report and see that the attribute persisted. No delay is
+ // expected for the first (priming) report.
+ [device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
+
+ [self waitForExpectations:@[ dataPersistedInitial ] timeout:60];
+
+ XCTestExpectation * dataPersisted1 = [self expectationWithDescription:@"data persisted 1"];
+ delegate.onClusterDataPersisted = ^{
+ os_unfair_lock_lock(&lock);
+ if (!dataPersistedTime) {
+ dataPersistedTime = [NSDate now];
+ }
+ os_unfair_lock_unlock(&lock);
+ [dataPersisted1 fulfill];
+ };
+
// Test 1: Inject report and see that the attribute persisted, with a delay
- [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
+ reportEndTime = nil;
+ dataPersistedTime = nil;
+ [device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
[self waitForExpectations:@[ dataPersisted1 ] timeout:60];
@@ -3762,20 +3780,20 @@
// 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];
+ [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];
+ [device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC));
- [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
+ [device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC));
- [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
+ [device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC));
- [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
+ [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
@@ -3817,7 +3835,7 @@
]]];
// Inject final report that makes MTRDevice recalculate delay with multiplier
- [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
+ [device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
[self waitForExpectations:@[ dataPersisted3 ] timeout:60];
@@ -3856,13 +3874,13 @@
]]];
// Inject report that makes MTRDevice detect the device is reporting excessively
- [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
+ [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];
+ [device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
NSTimeInterval elapsed = -[excessiveStartTime timeIntervalSinceNow];
if (elapsed > (baseTestDelayTime * 2 * 5 * 1.2)) {
break;
@@ -3879,7 +3897,7 @@
// And inject a report to trigger MTRDevice to recalculate that this device is no longer
// reporting excessively
- [device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
+ [device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
[self waitForExpectations:@[ dataPersisted4 ] timeout:60];
diff --git a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m
index 601cbcc..52b1ae3 100644
--- a/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m
+++ b/src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m
@@ -1437,29 +1437,29 @@
__auto_type * delegate = [[MTRDeviceTestDelegate alloc] init];
XCTestExpectation * subscriptionExpectation = [self expectationWithDescription:@"Subscription has been set up"];
- XCTestExpectation * gotClusterDataPersisted = nil;
- if (!disableStorageBehaviorOptimization) {
- gotClusterDataPersisted = [self expectationWithDescription:@"Cluster data persisted"];
- }
delegate.onReportEnd = ^{
[subscriptionExpectation fulfill];
};
- delegate.onClusterDataPersisted = ^{
- [gotClusterDataPersisted fulfill];
+
+ __block BOOL onDeviceCachePrimedCalled = NO;
+ delegate.onDeviceCachePrimed = ^{
+ onDeviceCachePrimedCalled = YES;
};
// Verify that initially (before we have ever subscribed while using this
// datastore) the device has no estimate for subscription latency.
XCTAssertNil(device.estimatedSubscriptionLatency);
+ // And that the device cache is not primed.
+ XCTAssertFalse(device.deviceCachePrimed);
+
[device setDelegate:delegate queue:queue];
[self waitForExpectations:@[ subscriptionExpectation ] timeout:60];
- if (!disableStorageBehaviorOptimization) {
- [self waitForExpectations:@[ gotClusterDataPersisted ] timeout:60];
- }
+ XCTAssertTrue(device.deviceCachePrimed);
+ XCTAssertTrue(onDeviceCachePrimedCalled);
NSUInteger dataStoreValuesCount = 0;
NSDictionary<MTRClusterPath *, MTRDeviceClusterData *> * dataStoreClusterData = [controller.controllerDataStore getStoredClusterDataForNodeID:deviceID];
@@ -1498,6 +1498,9 @@
// Check that the new device has an estimated subscription latency.
XCTAssertNotNil(device.estimatedSubscriptionLatency);
+ // And that it's already primed.
+ XCTAssertTrue(device.deviceCachePrimed);
+
// Check that this estimate is positive, since subscribing must have taken
// some time.
XCTAssertGreaterThan(device.estimatedSubscriptionLatency.doubleValue, 0);
@@ -1518,6 +1521,11 @@
[newDeviceGotClusterDataPersisted fulfill];
};
+ __block BOOL newOnDeviceCachePrimedCalled = NO;
+ newDelegate.onDeviceCachePrimed = ^{
+ newOnDeviceCachePrimedCalled = YES;
+ };
+
[newDevice setDelegate:newDelegate queue:queue];
[self waitForExpectations:@[ newDeviceSubscriptionExpectation ] timeout:60];
@@ -1526,6 +1534,8 @@
}
newDelegate.onReportEnd = nil;
+ XCTAssertFalse(newOnDeviceCachePrimedCalled);
+
// 1) MTRDevice actually gets some attributes reported more than once
// 2) Some attributes do change on resubscribe
// * With all-clusts-app as of 2024-02-10, out of 1287 persisted attributes, still 450 attributes were reported with filter
