Skip to content

Commit 6368d7d

Browse files
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.
1 parent 22a9dc3 commit 6368d7d

File tree

3 files changed

+82
-82
lines changed

3 files changed

+82
-82
lines changed

src/darwin/Framework/CHIP/MTRDevice.mm

+31-59
Original file line numberDiff line numberDiff line change
@@ -376,7 +376,11 @@ @implementation MTRDevice {
376376
#ifdef DEBUG
377377
NSUInteger _unitTestAttributesReportedSinceLastCheck;
378378
#endif
379-
BOOL _delegateDeviceCachePrimedCalled;
379+
380+
// _deviceCachePrimed is true if we have the data that comes from an initial
381+
// subscription priming report (whether it came from storage or from our
382+
// subscription).
383+
BOOL _deviceCachePrimed;
380384

381385
// _persistedClusterData stores data that we have already persisted (when we have
382386
// cluster data persistence enabled). Nil when we have no persistence enabled.
@@ -736,11 +740,6 @@ - (void)setDelegate:(id<MTRDeviceDelegate>)delegate queue:(dispatch_queue_t)queu
736740
_weakDelegate = [MTRWeakReference weakReferenceWithObject:delegate];
737741
_delegateQueue = queue;
738742

739-
// If Check if cache is already primed and client hasn't been informed yet, call the -deviceCachePrimed: callback
740-
if (!_delegateDeviceCachePrimedCalled && [self _isCachePrimedWithInitialConfigurationData]) {
741-
[self _callDelegateDeviceCachePrimed];
742-
}
743-
744743
if (setUpSubscription) {
745744
_initialSubscribeStart = [NSDate now];
746745
if ([self _deviceUsesThread]) {
@@ -915,7 +914,7 @@ - (BOOL)_callDelegateWithBlock:(void (^)(id<MTRDeviceDelegate>))block
915914
- (void)_callDelegateDeviceCachePrimed
916915
{
917916
os_unfair_lock_assert_owner(&self->_lock);
918-
_delegateDeviceCachePrimedCalled = [self _callDelegateWithBlock:^(id<MTRDeviceDelegate> delegate) {
917+
[self _callDelegateWithBlock:^(id<MTRDeviceDelegate> delegate) {
919918
if ([delegate respondsToSelector:@selector(deviceCachePrimed:)]) {
920919
[delegate deviceCachePrimed:self];
921920
}
@@ -994,11 +993,6 @@ - (void)_handleSubscriptionEstablished
994993
[self _changeInternalState:MTRInternalDeviceStateInitialSubscriptionEstablished];
995994
}
996995

997-
// As subscription is established, check if the delegate needs to be informed
998-
if (!_delegateDeviceCachePrimedCalled) {
999-
[self _callDelegateDeviceCachePrimed];
1000-
}
1001-
1002996
[self _changeState:MTRDeviceStateReachable];
1003997

1004998
// No need to monitor connectivity after subscription establishment
@@ -1480,6 +1474,13 @@ - (void)_scheduleClusterDataPersistence
14801474
return;
14811475
}
14821476

1477+
// If we have nothing stored at all yet, store directly, so we move into a
1478+
// primed state.
1479+
if (!_deviceCachePrimed) {
1480+
[self _persistClusterData];
1481+
return;
1482+
}
1483+
14831484
// Ensure there is an array to keep the most recent report times
14841485
if (!_mostRecentReportTimes) {
14851486
_mostRecentReportTimes = [NSMutableArray array];
@@ -1525,7 +1526,7 @@ - (void)_scheduleClusterDataPersistence
15251526

15261527
// Set current multiplier to [1, MaxMultiplier]
15271528
_reportToPersistenceDelayCurrentMultiplier = 1 + (proportionTowardMinThreshold * (_storageBehaviorConfiguration.reportToPersistenceDelayMaxMultiplier - 1));
1528-
MTR_LOG("%@ storage behavior: device reporting frequently - setting delay multiplied to %lf", self, _reportToPersistenceDelayCurrentMultiplier);
1529+
MTR_LOG("%@ storage behavior: device reporting frequently - setting delay multiplier to %lf", self, _reportToPersistenceDelayCurrentMultiplier);
15291530
} else {
15301531
_reportToPersistenceDelayCurrentMultiplier = 1;
15311532
}
@@ -1601,6 +1602,19 @@ - (void)_handleReportEnd
16011602
_deviceConfigurationChanged = NO;
16021603
}
16031604

1605+
// Do this after the _deviceConfigurationChanged check, so that we don't
1606+
// call deviceConfigurationChanged: immediately after telling our delegate
1607+
// we are now primed.
1608+
//
1609+
// TODO: Maybe we shouldn't dispatch deviceConfigurationChanged: for the
1610+
// initial priming bits?
1611+
if (!_deviceCachePrimed) {
1612+
// This is the end of the priming sequence of data reports, so we have
1613+
// all the data for the device now.
1614+
_deviceCachePrimed = YES;
1615+
[self _callDelegateDeviceCachePrimed];
1616+
}
1617+
16041618
// For unit testing only
16051619
#ifdef DEBUG
16061620
id delegate = _weakDelegate.strongObject;
@@ -3165,10 +3179,9 @@ - (void)setPersistedClusterData:(NSDictionary<MTRClusterPath *, MTRDeviceCluster
31653179
[_persistedClusterData setObject:clusterData[clusterPath] forKey:clusterPath];
31663180
}
31673181

3168-
// 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
3169-
if ([self _isCachePrimedWithInitialConfigurationData]) {
3170-
_delegateDeviceCachePrimedCalled = YES;
3171-
}
3182+
// We have some stored data. Since we don't store data until the end of the
3183+
// initial priming report, our device cache must be primed.
3184+
_deviceCachePrimed = YES;
31723185
}
31733186

31743187
- (void)_setLastInitialSubscribeLatency:(id)latency
@@ -3218,7 +3231,7 @@ - (void)_storePersistedDeviceData
32183231
- (BOOL)deviceCachePrimed
32193232
{
32203233
std::lock_guard lock(_lock);
3221-
return [self _isCachePrimedWithInitialConfigurationData];
3234+
return _deviceCachePrimed;
32223235
}
32233236

32243237
// If value is non-nil, associate with expectedValueID
@@ -3395,47 +3408,6 @@ - (void)_removeExpectedValueForAttributePath:(MTRAttributePath *)attributePath e
33953408
}
33963409
}
33973410

3398-
// This method checks if there is a need to inform delegate that the attribute cache has been "primed"
3399-
- (BOOL)_isCachePrimedWithInitialConfigurationData
3400-
{
3401-
os_unfair_lock_assert_owner(&self->_lock);
3402-
3403-
// Check if root node descriptor exists
3404-
MTRDeviceDataValueDictionary rootDescriptorPartsListDataValue = [self _cachedAttributeValueForPath:[MTRAttributePath attributePathWithEndpointID:@(kRootEndpointId) clusterID:@(MTRClusterIDTypeDescriptorID) attributeID:@(MTRAttributeIDTypeClusterDescriptorAttributePartsListID)]];
3405-
if (!rootDescriptorPartsListDataValue || ![MTRArrayValueType isEqualToString:rootDescriptorPartsListDataValue[MTRTypeKey]]) {
3406-
return NO;
3407-
}
3408-
NSArray * partsList = rootDescriptorPartsListDataValue[MTRValueKey];
3409-
if (![partsList isKindOfClass:[NSArray class]] || !partsList.count) {
3410-
MTR_LOG_ERROR("%@ unexpected type %@ for parts list %@", self, [partsList class], partsList);
3411-
return NO;
3412-
}
3413-
3414-
// Check if we have cached descriptor clusters for each listed endpoint
3415-
for (NSDictionary * endpointDictionary in partsList) {
3416-
NSDictionary * endpointDataValue = endpointDictionary[MTRDataKey];
3417-
if (![endpointDataValue isKindOfClass:[NSDictionary class]]) {
3418-
MTR_LOG_ERROR("%@ unexpected parts list dictionary %@ data value class %@", self, endpointDictionary, [endpointDataValue class]);
3419-
continue;
3420-
}
3421-
if (![MTRUnsignedIntegerValueType isEqual:endpointDataValue[MTRTypeKey]]) {
3422-
MTR_LOG_ERROR("%@ unexpected parts list data value %@ item type %@", self, endpointDataValue, endpointDataValue[MTRTypeKey]);
3423-
continue;
3424-
}
3425-
NSNumber * endpoint = endpointDataValue[MTRValueKey];
3426-
if (![endpoint isKindOfClass:[NSNumber class]]) {
3427-
MTR_LOG_ERROR("%@ unexpected parts list item value class %@", self, [endpoint class]);
3428-
continue;
3429-
}
3430-
MTRDeviceDataValueDictionary descriptorDeviceTypeListDataValue = [self _cachedAttributeValueForPath:[MTRAttributePath attributePathWithEndpointID:endpoint clusterID:@(MTRClusterIDTypeDescriptorID) attributeID:@(MTRAttributeIDTypeClusterDescriptorAttributeDeviceTypeListID)]];
3431-
if (![MTRArrayValueType isEqualToString:descriptorDeviceTypeListDataValue[MTRTypeKey]] || !descriptorDeviceTypeListDataValue[MTRValueKey]) {
3432-
return NO;
3433-
}
3434-
}
3435-
3436-
return YES;
3437-
}
3438-
34393411
- (MTRBaseDevice *)newBaseDevice
34403412
{
34413413
return [MTRBaseDevice deviceWithNodeID:self.nodeID controller:self.deviceController];

src/darwin/Framework/CHIPTests/MTRDeviceTests.m

+32-14
Original file line numberDiff line numberDiff line change
@@ -3669,7 +3669,7 @@ - (void)test035_TestMTRDeviceSubscriptionNotEstablishedOverXPC
36693669
XCTAssertEqual([device _getInternalState], MTRInternalDeviceStateUnsubscribed);
36703670
}
36713671

3672-
- (NSArray<NSDictionary<NSString *, id> *> *)testAttributeReportWithValue:(unsigned int)testValue
3672+
- (NSArray<NSDictionary<NSString *, id> *> *)_testAttributeReportWithValue:(unsigned int)testValue
36733673
{
36743674
return @[ @{
36753675
MTRAttributePathKey : [MTRAttributePath attributePathWithEndpointID:@(0) clusterID:@(MTRClusterIDTypeLevelControlID) attributeID:@(MTRAttributeIDTypeClusterLevelControlAttributeCurrentLevelID)],
@@ -3696,7 +3696,7 @@ - (void)test036_TestStorageBehaviorConfiguration
36963696
__block NSDate * reportEndTime = nil;
36973697
__block NSDate * dataPersistedTime = nil;
36983698

3699-
XCTestExpectation * dataPersisted1 = [self expectationWithDescription:@"data persisted 1"];
3699+
XCTestExpectation * dataPersistedInitial = [self expectationWithDescription:@"data persisted initial"];
37003700
delegate.onReportEnd = ^() {
37013701
os_unfair_lock_lock(&lock);
37023702
if (!reportEndTime) {
@@ -3711,7 +3711,7 @@ - (void)test036_TestStorageBehaviorConfiguration
37113711
dataPersistedTime = [NSDate now];
37123712
}
37133713
os_unfair_lock_unlock(&lock);
3714-
[dataPersisted1 fulfill];
3714+
[dataPersistedInitial fulfill];
37153715
};
37163716

37173717
// Do not subscribe - only inject sequence of reports to control the timing
@@ -3732,11 +3732,29 @@ - (void)test036_TestStorageBehaviorConfiguration
37323732

37333733
[device setDelegate:delegate queue:queue];
37343734

3735-
// Use a mutable dictionary so the data value can be easily changed between reports
3735+
// Use a counter that will be incremented for each report as the value.
37363736
unsigned int currentTestValue = 1;
37373737

3738+
// Initial setup: Inject report and see that the attribute persisted. No delay is
3739+
// expected for the first (priming) report.
3740+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3741+
3742+
[self waitForExpectations:@[ dataPersistedInitial ] timeout:60];
3743+
3744+
XCTestExpectation * dataPersisted1 = [self expectationWithDescription:@"data persisted 1"];
3745+
delegate.onClusterDataPersisted = ^{
3746+
os_unfair_lock_lock(&lock);
3747+
if (!dataPersistedTime) {
3748+
dataPersistedTime = [NSDate now];
3749+
}
3750+
os_unfair_lock_unlock(&lock);
3751+
[dataPersisted1 fulfill];
3752+
};
3753+
37383754
// Test 1: Inject report and see that the attribute persisted, with a delay
3739-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3755+
reportEndTime = nil;
3756+
dataPersistedTime = nil;
3757+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
37403758

37413759
[self waitForExpectations:@[ dataPersisted1 ] timeout:60];
37423760

@@ -3762,20 +3780,20 @@ - (void)test036_TestStorageBehaviorConfiguration
37623780
// Test 2: Inject multiple reports with delay and see that the attribute persisted eventually
37633781
reportEndTime = nil;
37643782
dataPersistedTime = nil;
3765-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3783+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
37663784

37673785
double frequentReportMultiplier = 0.5;
37683786
usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC));
3769-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3787+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
37703788

37713789
usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC));
3772-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3790+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
37733791

37743792
usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC));
3775-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3793+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
37763794

37773795
usleep((useconds_t) (baseTestDelayTime * frequentReportMultiplier * USEC_PER_SEC));
3778-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3796+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
37793797

37803798
// At this point, the threshold for reportToPersistenceDelayTimeMax should have hit, and persistence
37813799
// should have happened with timer running down to persist again with the 5th report above. Need to
@@ -3817,7 +3835,7 @@ - (void)test036_TestStorageBehaviorConfiguration
38173835
]]];
38183836

38193837
// Inject final report that makes MTRDevice recalculate delay with multiplier
3820-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3838+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
38213839

38223840
[self waitForExpectations:@[ dataPersisted3 ] timeout:60];
38233841

@@ -3856,13 +3874,13 @@ - (void)test036_TestStorageBehaviorConfiguration
38563874
]]];
38573875

38583876
// Inject report that makes MTRDevice detect the device is reporting excessively
3859-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3877+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
38603878

38613879
// Now keep reporting excessively for base delay time max times max multiplier, plus a bit more
38623880
NSDate * excessiveStartTime = [NSDate now];
38633881
for (;;) {
38643882
usleep((useconds_t) (baseTestDelayTime * 0.1 * USEC_PER_SEC));
3865-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3883+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
38663884
NSTimeInterval elapsed = -[excessiveStartTime timeIntervalSinceNow];
38673885
if (elapsed > (baseTestDelayTime * 2 * 5 * 1.2)) {
38683886
break;
@@ -3879,7 +3897,7 @@ - (void)test036_TestStorageBehaviorConfiguration
38793897

38803898
// And inject a report to trigger MTRDevice to recalculate that this device is no longer
38813899
// reporting excessively
3882-
[device unitTestInjectAttributeReport:[self testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
3900+
[device unitTestInjectAttributeReport:[self _testAttributeReportWithValue:currentTestValue++] fromSubscription:YES];
38833901

38843902
[self waitForExpectations:@[ dataPersisted4 ] timeout:60];
38853903

src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m

+19-9
Original file line numberDiff line numberDiff line change
@@ -1437,29 +1437,29 @@ - (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id<MTRDeviceControllerStora
14371437
__auto_type * delegate = [[MTRDeviceTestDelegate alloc] init];
14381438

14391439
XCTestExpectation * subscriptionExpectation = [self expectationWithDescription:@"Subscription has been set up"];
1440-
XCTestExpectation * gotClusterDataPersisted = nil;
1441-
if (!disableStorageBehaviorOptimization) {
1442-
gotClusterDataPersisted = [self expectationWithDescription:@"Cluster data persisted"];
1443-
}
14441440

14451441
delegate.onReportEnd = ^{
14461442
[subscriptionExpectation fulfill];
14471443
};
1448-
delegate.onClusterDataPersisted = ^{
1449-
[gotClusterDataPersisted fulfill];
1444+
1445+
__block BOOL onDeviceCachePrimedCalled = NO;
1446+
delegate.onDeviceCachePrimed = ^{
1447+
onDeviceCachePrimedCalled = YES;
14501448
};
14511449

14521450
// Verify that initially (before we have ever subscribed while using this
14531451
// datastore) the device has no estimate for subscription latency.
14541452
XCTAssertNil(device.estimatedSubscriptionLatency);
14551453

1454+
// And that the device cache is not primed.
1455+
XCTAssertFalse(device.deviceCachePrimed);
1456+
14561457
[device setDelegate:delegate queue:queue];
14571458

14581459
[self waitForExpectations:@[ subscriptionExpectation ] timeout:60];
14591460

1460-
if (!disableStorageBehaviorOptimization) {
1461-
[self waitForExpectations:@[ gotClusterDataPersisted ] timeout:60];
1462-
}
1461+
XCTAssertTrue(device.deviceCachePrimed);
1462+
XCTAssertTrue(onDeviceCachePrimedCalled);
14631463

14641464
NSUInteger dataStoreValuesCount = 0;
14651465
NSDictionary<MTRClusterPath *, MTRDeviceClusterData *> * dataStoreClusterData = [controller.controllerDataStore getStoredClusterDataForNodeID:deviceID];
@@ -1498,6 +1498,9 @@ - (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id<MTRDeviceControllerStora
14981498
// Check that the new device has an estimated subscription latency.
14991499
XCTAssertNotNil(device.estimatedSubscriptionLatency);
15001500

1501+
// And that it's already primed.
1502+
XCTAssertTrue(device.deviceCachePrimed);
1503+
15011504
// Check that this estimate is positive, since subscribing must have taken
15021505
// some time.
15031506
XCTAssertGreaterThan(device.estimatedSubscriptionLatency.doubleValue, 0);
@@ -1518,6 +1521,11 @@ - (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id<MTRDeviceControllerStora
15181521
[newDeviceGotClusterDataPersisted fulfill];
15191522
};
15201523

1524+
__block BOOL newOnDeviceCachePrimedCalled = NO;
1525+
newDelegate.onDeviceCachePrimed = ^{
1526+
newOnDeviceCachePrimedCalled = YES;
1527+
};
1528+
15211529
[newDevice setDelegate:newDelegate queue:queue];
15221530

15231531
[self waitForExpectations:@[ newDeviceSubscriptionExpectation ] timeout:60];
@@ -1526,6 +1534,8 @@ - (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id<MTRDeviceControllerStora
15261534
}
15271535
newDelegate.onReportEnd = nil;
15281536

1537+
XCTAssertFalse(newOnDeviceCachePrimedCalled);
1538+
15291539
// 1) MTRDevice actually gets some attributes reported more than once
15301540
// 2) Some attributes do change on resubscribe
15311541
// * With all-clusts-app as of 2024-02-10, out of 1287 persisted attributes, still 450 attributes were reported with filter

0 commit comments

Comments
 (0)