Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Provide an estimate of subscription latency in MTRDevice. #33490

Merged
Merged
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions src/darwin/Framework/CHIP/MTRDevice.h
Original file line number Diff line number Diff line change
@@ -101,6 +101,14 @@ MTR_AVAILABLE(ios(16.1), macos(13.0), watchos(9.1), tvos(16.1))
*/
@property (nonatomic, readonly, copy) NSNumber * nodeID NS_REFINED_FOR_SWIFT MTR_AVAILABLE(ios(17.4), macos(14.4), watchos(10.4), tvos(17.4));

/**
* An estimate of how much time is likely to elapse between setDelegate being
* called and the current device state (attributes, stored events) being known.
*
* nil if no such estimate is available. Otherwise, the NSNumber stores an NSTimeInterval.
*/
@property (nonatomic, readonly, nullable, copy) NSNumber * estimatedSubscriptionLatency MTR_NEWLY_AVAILABLE;

/**
* Set the delegate to receive asynchronous callbacks about the device.
*
62 changes: 62 additions & 0 deletions src/darwin/Framework/CHIP/MTRDevice.mm
Original file line number Diff line number Diff line change
@@ -213,6 +213,7 @@ @implementation MTRDeviceClusterData {

static NSString * const sDataVersionKey = @"dataVersion";
static NSString * const sAttributesKey = @"attributes";
static NSString * const sLastInitialSubscribeLatencyKey = @"lastInitialSubscribeLatency";

- (void)storeValue:(MTRDeviceDataValueDictionary _Nullable)value forAttribute:(NSNumber *)attribute
{
@@ -414,6 +415,10 @@ @implementation MTRDevice {
// 2. OnResubscriptionNeeded is called
// 3. Subscription reset (including when getSessionForNode fails)
MTRAsyncWorkCompletionBlock _subscriptionPoolWorkCompletionBlock;

// Tracking of initial subscribe latency. When _initialSubscribeStart is
// nil, we are not tracking the latency.
NSDate * _Nullable _initialSubscribeStart;
}

- (instancetype)initWithNodeID:(NSNumber *)nodeID controller:(MTRDeviceController *)controller
@@ -705,6 +710,7 @@ - (void)setDelegate:(id<MTRDeviceDelegate>)delegate queue:(dispatch_queue_t)queu
}

if (setUpSubscription) {
_initialSubscribeStart = [NSDate now];
if ([self _deviceUsesThread]) {
[self _scheduleSubscriptionPoolWork:^{
std::lock_guard lock(self->_lock);
@@ -954,6 +960,18 @@ - (void)_handleSubscriptionEstablished
// No need to monitor connectivity after subscription establishment
[self _stopConnectivityMonitoring];

auto initialSubscribeStart = _initialSubscribeStart;
// We no longer need to track subscribe latency for this device.
_initialSubscribeStart = nil;

if (initialSubscribeStart != nil) {
// We want time interval from initialSubscribeStart to now, not the other
// way around.
NSTimeInterval subscriptionLatency = -[initialSubscribeStart timeIntervalSinceNow];
_estimatedSubscriptionLatency = @(subscriptionLatency);
[self _storePersistedDeviceData];
}

os_unfair_lock_unlock(&self->_lock);

os_unfair_lock_lock(&self->_timeSyncLock);
@@ -2884,6 +2902,50 @@ - (void)setPersistedClusterData:(NSDictionary<MTRClusterPath *, MTRDeviceCluster
}
}

- (void)_setLastInitialSubscribeLatency:(id)latency
{
os_unfair_lock_assert_owner(&self->_lock);

if (![latency isKindOfClass:NSNumber.class]) {
// Unexpected value of some sort; just ignore it.
return;
}

_estimatedSubscriptionLatency = latency;
}

- (void)setPersistedDeviceData:(NSDictionary<NSString *, id> *)data
{
MTR_LOG_INFO("%@ setPersistedDeviceData: %@", self, data);

std::lock_guard lock(_lock);

// For now the only data we care about is our initial subscribe latency.
id initialSubscribeLatency = data[sLastInitialSubscribeLatencyKey];
if (initialSubscribeLatency != nil) {
[self _setLastInitialSubscribeLatency:initialSubscribeLatency];
}
}

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

auto datastore = _deviceController.controllerDataStore;
if (datastore == nil) {
// No way to store.
return;
}

// For now the only data we have is our initial subscribe latency.
NSMutableDictionary<NSString *, id> * data = [NSMutableDictionary dictionary];
if (_estimatedSubscriptionLatency != nil) {
data[sLastInitialSubscribeLatencyKey] = _estimatedSubscriptionLatency;
}

[datastore storeDeviceData:[data copy] forNodeID:self.nodeID];
}

- (BOOL)deviceCachePrimed
{
std::lock_guard lock(_lock);
10 changes: 9 additions & 1 deletion src/darwin/Framework/CHIP/MTRDeviceController.mm
Original file line number Diff line number Diff line change
@@ -966,7 +966,7 @@ - (MTRDevice *)_setupDeviceForNodeID:(NSNumber *)nodeID prefetchedClusterData:(N
if (prefetchedClusterData.count) {
[deviceToReturn setPersistedClusterData:prefetchedClusterData];
}
} else {
} else if (_controllerDataStore) {
// Load persisted cluster data if they exist.
NSDictionary * clusterData = [_controllerDataStore getStoredClusterDataForNodeID:nodeID];
MTR_LOG_INFO("Loaded %lu cluster data from storage for %@", static_cast<unsigned long>(clusterData.count), deviceToReturn);
@@ -975,6 +975,14 @@ - (MTRDevice *)_setupDeviceForNodeID:(NSNumber *)nodeID prefetchedClusterData:(N
}
}

// TODO: Figure out how to get the device data as part of our bulk-read bits.
if (_controllerDataStore) {
auto * deviceData = [_controllerDataStore getStoredDeviceDataForNodeID:nodeID];
if (deviceData.count) {
[deviceToReturn setPersistedDeviceData:deviceData];
}
}

return deviceToReturn;
}

10 changes: 10 additions & 0 deletions src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.h
Original file line number Diff line number Diff line change
@@ -78,6 +78,16 @@ typedef void (^MTRDeviceControllerDataStoreClusterDataHandler)(NSDictionary<NSNu
- (void)clearStoredClusterDataForNodeID:(NSNumber *)nodeID;
- (void)clearAllStoredClusterData;

/**
* Storage for miscellaneous MTRDevice data that only needs to be stored
* locally.
*
* storeDeviceData uses data and nodeID async without copying, so callers should
* not modify the passed-in dictionary or nodeID.
*/
- (nullable NSDictionary<NSString *, id> *)getStoredDeviceDataForNodeID:(NSNumber *)nodeID;
- (void)storeDeviceData:(NSDictionary<NSString *, id> *)data forNodeID:(NSNumber *)nodeID;

@end

NS_ASSUME_NONNULL_END
59 changes: 59 additions & 0 deletions src/darwin/Framework/CHIP/MTRDeviceControllerDataStore.mm
Original file line number Diff line number Diff line change
@@ -1020,6 +1020,65 @@ - (void)storeClusterData:(NSDictionary<MTRClusterPath *, MTRDeviceClusterData *>
});
}

static NSString * sDeviceDataKeyPrefix = @"deviceData";

- (NSString *)_deviceDataKeyForNodeID:(NSNumber *)nodeID
{
return [sDeviceDataKeyPrefix stringByAppendingFormat:@":0x%016llX", nodeID.unsignedLongLongValue];
}

- (nullable NSDictionary<NSString *, id> *)getStoredDeviceDataForNodeID:(NSNumber *)nodeID
{
__block NSDictionary<NSString *, id> * deviceData = nil;
dispatch_sync(_storageDelegateQueue, ^{
MTRDeviceController * controller = self->_controller;
VerifyOrReturn(controller != nil); // No way to call delegate without controller.

id data;
@autoreleasepool {
data = [self->_storageDelegate controller:controller
valueForKey:[self _deviceDataKeyForNodeID:nodeID]
securityLevel:MTRStorageSecurityLevelSecure
sharingType:MTRStorageSharingTypeNotShared];
}
if (data == nil) {
return;
}

if (![data isKindOfClass:NSDictionary.class]) {
return;
}

// Check that all the keys are in fact strings.
NSDictionary * dictionary = data;
for (id key in dictionary) {
if (![key isKindOfClass:NSString.class]) {
return;
}
}

// We can't do value type verification; our API consumer will need
// to do that.
deviceData = dictionary;
});
return deviceData;
}

- (void)storeDeviceData:(NSDictionary<NSString *, id> *)data forNodeID:(NSNumber *)nodeID
{
dispatch_async(_storageDelegateQueue, ^{
MTRDeviceController * controller = self->_controller;
VerifyOrReturn(controller != nil); // No way to call delegate without controller.

// Ignore store failures, since they are not actionable for us here.
[self->_storageDelegate controller:controller
storeValue:data
forKey:[self _deviceDataKeyForNodeID:nodeID]
securityLevel:MTRStorageSecurityLevelSecure
sharingType:MTRStorageSharingTypeNotShared];
});
}

@end

@implementation MTRCASESessionResumptionInfo
3 changes: 3 additions & 0 deletions src/darwin/Framework/CHIP/MTRDevice_Internal.h
Original file line number Diff line number Diff line change
@@ -86,6 +86,9 @@ MTR_TESTABLE
// Contains data version information and attribute values.
- (void)setPersistedClusterData:(NSDictionary<MTRClusterPath *, MTRDeviceClusterData *> *)clusterData;

// Method to insert persisted data that pertains to the whole device.
- (void)setPersistedDeviceData:(NSDictionary<NSString *, id> *)data;

#ifdef DEBUG
- (NSUInteger)unitTestAttributeCount;
#endif
23 changes: 23 additions & 0 deletions src/darwin/Framework/CHIPTests/MTRPerControllerStorageTests.m
Original file line number Diff line number Diff line change
@@ -1362,10 +1362,18 @@ - (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id<MTRDeviceControllerStora
[subscriptionExpectation fulfill];
};

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

__auto_type * beforeSetDelegate = [NSDate now];

[device setDelegate:delegate queue:queue];

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

__auto_type * afterInitialSubscription = [NSDate now];

NSUInteger dataStoreValuesCount = 0;
NSDictionary<MTRClusterPath *, MTRDeviceClusterData *> * dataStoreClusterData = [controller.controllerDataStore getStoredClusterDataForNodeID:deviceID];
for (MTRClusterPath * path in dataStoreClusterData) {
@@ -1400,6 +1408,21 @@ - (void)doDataStoreMTRDeviceTestWithStorageDelegate:(id<MTRDeviceControllerStora
double storedAttributeDifferFromMTRDevicePercentage = storedAttributeDifferFromMTRDeviceCount * 100.0 / dataStoreValuesCount;
XCTAssertTrue(storedAttributeDifferFromMTRDevicePercentage < 10.0);

// Check that the new device has an estimated subscription latency.
XCTAssertNotNil(device.estimatedSubscriptionLatency);

// Check that this estimate is positive, since subscribing must have taken
// some time.
XCTAssertGreaterThan(device.estimatedSubscriptionLatency.doubleValue, 0);

// Check that this estimate is no larger than the measured latency observed
// above. Unfortunately, We measure our observed latency to report end, not
// to the immediately following internal subscription established
// notification, so in fact our measured value can end up shorter than the
// estimated latency the device has. Add some slop to handle that.
const NSTimeInterval timingSlopInSeconds = 0.1;
XCTAssertLessThanOrEqual(device.estimatedSubscriptionLatency.doubleValue, [afterInitialSubscription timeIntervalSinceDate:beforeSetDelegate] + timingSlopInSeconds);

// Now set up new delegate for the new device and verify that once subscription reestablishes, the data version filter loaded from storage will work
__auto_type * newDelegate = [[MTRDeviceTestDelegate alloc] init];