Improve description for MTRDevice. (#34857)
* apply changes from PR #34797 to to concrete class
* Improve description for MTRDevice.
Includes various information that wasn't included before but probably should be.
* Address review comments.
---------
Co-authored-by: Kiel Oleson <kielo@apple.com>
diff --git a/src/darwin/Framework/CHIP/MTRAsyncWorkQueue.h b/src/darwin/Framework/CHIP/MTRAsyncWorkQueue.h
index 598bbf0..f147307 100644
--- a/src/darwin/Framework/CHIP/MTRAsyncWorkQueue.h
+++ b/src/darwin/Framework/CHIP/MTRAsyncWorkQueue.h
@@ -228,6 +228,9 @@
- (BOOL)hasDuplicateForTypeID:(NSUInteger)opaqueDuplicateTypeID
workItemData:(id)opaqueWorkItemData;
+// Returns current count of queued items.
+- (NSUInteger)itemCount;
+
/// Cancels and removes all work items.
- (void)invalidate;
@end
diff --git a/src/darwin/Framework/CHIP/MTRAsyncWorkQueue.mm b/src/darwin/Framework/CHIP/MTRAsyncWorkQueue.mm
index 4d82fde..de3faee 100644
--- a/src/darwin/Framework/CHIP/MTRAsyncWorkQueue.mm
+++ b/src/darwin/Framework/CHIP/MTRAsyncWorkQueue.mm
@@ -433,6 +433,12 @@
return NO;
}
+- (NSUInteger)itemCount
+{
+ std::lock_guard lock(_lock);
+ return _items.count;
+}
+
@end
NS_ASSUME_NONNULL_END
diff --git a/src/darwin/Framework/CHIP/MTRDevice.mm b/src/darwin/Framework/CHIP/MTRDevice.mm
index 9ce2e3d..d8fc52b 100644
--- a/src/darwin/Framework/CHIP/MTRDevice.mm
+++ b/src/darwin/Framework/CHIP/MTRDevice.mm
@@ -209,6 +209,24 @@
{
return state == MTRInternalDeviceStateInitialSubscriptionEstablished || state == MTRInternalDeviceStateLaterSubscriptionEstablished;
}
+
+NSString * InternalDeviceStateString(MTRInternalDeviceState state)
+{
+ switch (state) {
+ case MTRInternalDeviceStateUnsubscribed:
+ return @"Unsubscribed";
+ case MTRInternalDeviceStateSubscribing:
+ return @"Subscribing";
+ case MTRInternalDeviceStateInitialSubscriptionEstablished:
+ return @"InitialSubscriptionEstablished";
+ case MTRInternalDeviceStateResubscribing:
+ return @"Resubscribing";
+ case MTRInternalDeviceStateLaterSubscriptionEstablished:
+ return @"LaterSubscriptionEstablished";
+ default:
+ return @"Unknown";
+ }
+}
} // anonymous namespace
typedef NS_ENUM(NSUInteger, MTRDeviceExpectedValueFieldIndex) {
@@ -355,8 +373,11 @@
@interface MTRDevice ()
@property (nonatomic, readonly) os_unfair_lock lock; // protects the caches and device state
// protects against concurrent time updates by guarding timeUpdateScheduled flag which manages time updates scheduling,
-// and protects device calls to setUTCTime and setDSTOffset
+// and protects device calls to setUTCTime and setDSTOffset. This can't just be replaced with "lock", because the time
+// update code calls public APIs like readAttributeWithEndpointID:.. (which attempt to take "lock") while holding
+// whatever lock protects the time sync bits.
@property (nonatomic, readonly) os_unfair_lock timeSyncLock;
+
@property (nonatomic) chip::FabricIndex fabricIndex;
@property (nonatomic) NSMutableArray<NSDictionary<NSString *, id> *> * unreportedEvents;
@property (nonatomic) BOOL receivingReport;
@@ -482,6 +503,27 @@
id _systemTimeChangeObserverToken;
NSMutableSet<MTRDeviceDelegateInfo *> * _delegates;
+
+ // Protects mutable state used by our description getter. This is a separate lock from "lock"
+ // so that we don't need to worry about getting our description while holding "lock" (e.g due to
+ // logging self). This lock _must_ be held narrowly, with no other lock acquisitions allowed
+ // while it's held, to avoid deadlock.
+ os_unfair_lock _descriptionLock;
+
+ // State used by our description getter: access to these must be protected by descriptionLock.
+ NSNumber * _Nullable _vid; // nil if unknown
+ NSNumber * _Nullable _pid; // nil if unknown
+ // _allNetworkFeatures is a bitwise or of the feature maps of all network commissioning clusters
+ // present on the device, or nil if there aren't any.
+ NSNumber * _Nullable _allNetworkFeatures;
+ // Copy of _internalDeviceState that is safe to use in description.
+ MTRInternalDeviceState _internalDeviceStateForDescription;
+ // Copy of _lastSubscriptionAttemptWait that is safe to use in description.
+ uint32_t _lastSubscriptionAttemptWaitForDescription;
+ // Most recent entry in _mostRecentReportTimes, if any.
+ NSDate * _Nullable _mostRecentReportTimeForDescription;
+ // Copy of _lastSubscriptionFailureTime that is safe to use in description.
+ NSDate * _Nullable _lastSubscriptionFailureTimeForDescription;
}
- (instancetype)initForSubclasses
@@ -498,6 +540,7 @@
if (self = [super init]) {
_lock = OS_UNFAIR_LOCK_INIT;
_timeSyncLock = OS_UNFAIR_LOCK_INIT;
+ _descriptionLock = OS_UNFAIR_LOCK_INIT;
_nodeID = [nodeID copy];
_fabricIndex = controller.fabricIndex;
_deviceController = controller;
@@ -507,6 +550,7 @@
_asyncWorkQueue = [[MTRAsyncWorkQueue alloc] initWithContext:self];
_state = MTRDeviceStateUnknown;
_internalDeviceState = MTRInternalDeviceStateUnsubscribed;
+ _internalDeviceStateForDescription = MTRInternalDeviceStateUnsubscribed;
if (controller.controllerDataStore) {
_persistedClusterData = [[NSCache alloc] init];
} else {
@@ -543,8 +587,58 @@
- (NSString *)description
{
+ id _Nullable vid;
+ id _Nullable pid;
+ NSNumber * _Nullable networkFeatures;
+ MTRInternalDeviceState internalDeviceState;
+ uint32_t lastSubscriptionAttemptWait;
+ NSDate * _Nullable mostRecentReportTime;
+ NSDate * _Nullable lastSubscriptionFailureTime;
+ {
+ std::lock_guard lock(_descriptionLock);
+ vid = _vid;
+ pid = _pid;
+ networkFeatures = _allNetworkFeatures;
+ internalDeviceState = _internalDeviceStateForDescription;
+ lastSubscriptionAttemptWait = _lastSubscriptionAttemptWaitForDescription;
+ mostRecentReportTime = _mostRecentReportTimeForDescription;
+ lastSubscriptionFailureTime = _lastSubscriptionFailureTimeForDescription;
+ }
+
+ if (vid == nil) {
+ vid = @"Unknown";
+ }
+
+ if (pid == nil) {
+ pid = @"Unknown";
+ }
+
+ NSString * wifi;
+ NSString * thread;
+ if (networkFeatures == nil) {
+ wifi = @"NO";
+ thread = @"NO";
+ } else {
+ wifi = YES_NO(networkFeatures.unsignedLongLongValue & MTRNetworkCommissioningFeatureWiFiNetworkInterface);
+ thread = YES_NO(networkFeatures.unsignedLongLongValue & MTRNetworkCommissioningFeatureThreadNetworkInterface);
+ }
+
+ NSString * reportAge;
+ if (mostRecentReportTime) {
+ reportAge = [NSString stringWithFormat:@" (%.0lfs ago)", -[mostRecentReportTime timeIntervalSinceNow]];
+ } else {
+ reportAge = @"";
+ }
+
+ NSString * subscriptionFailureAge;
+ if (lastSubscriptionFailureTime) {
+ subscriptionFailureAge = [NSString stringWithFormat:@" (%.0lfs ago)", -[lastSubscriptionFailureTime timeIntervalSinceNow]];
+ } else {
+ subscriptionFailureAge = @"";
+ }
+
return [NSString
- stringWithFormat:@"<MTRDevice: %p>[fabric: %u, nodeID: 0x%016llX]", self, _fabricIndex, _nodeID.unsignedLongLongValue];
+ stringWithFormat:@"<MTRDevice: %p, node: %016llX-%016llX (%llu), VID: %@, PID: %@, WiFi: %@, Thread: %@, state: %@, last subscription attempt wait: %lus, queued work: %lu, last report: %@%@, last subscription failure: %@%@, controller: %@>", self, _deviceController.compressedFabricID.unsignedLongLongValue, _nodeID.unsignedLongLongValue, _nodeID.unsignedLongLongValue, vid, pid, wifi, thread, InternalDeviceStateString(internalDeviceState), static_cast<unsigned long>(lastSubscriptionAttemptWait), static_cast<unsigned long>(_asyncWorkQueue.itemCount), mostRecentReportTime, reportAge, lastSubscriptionFailureTime, subscriptionFailureAge, _deviceController.uniqueIdentifier];
}
+ (MTRDevice *)deviceWithNodeID:(NSNumber *)nodeID controller:(MTRDeviceController *)controller
@@ -661,13 +755,11 @@
- (NSArray<NSNumber *> *)_endpointsWithTimeSyncClusterServer
{
- auto partsList = [self readAttributeWithEndpointID:@(0) clusterID:@(MTRClusterIDTypeDescriptorID) attributeID:@(MTRAttributeIDTypeClusterDescriptorAttributePartsListID) params:nil];
- NSMutableArray<NSNumber *> * endpointsOnDevice = [self arrayOfNumbersFromAttributeValue:partsList];
- if (!endpointsOnDevice) {
- endpointsOnDevice = [[NSMutableArray<NSNumber *> alloc] init];
+ NSArray<NSNumber *> * endpointsOnDevice;
+ {
+ std::lock_guard lock(_lock);
+ endpointsOnDevice = [self _endpointList];
}
- // Add Root node!
- [endpointsOnDevice addObject:@(0)];
NSMutableArray<NSNumber *> * endpointsWithTimeSyncCluster = [[NSMutableArray<NSNumber *> alloc] init];
for (NSNumber * endpoint in endpointsOnDevice) {
@@ -1160,6 +1252,10 @@
os_unfair_lock_assert_owner(&self->_lock);
MTRInternalDeviceState lastState = _internalDeviceState;
_internalDeviceState = state;
+ {
+ std::lock_guard lock(_descriptionLock);
+ _internalDeviceStateForDescription = _internalDeviceState;
+ }
if (lastState != state) {
MTR_LOG("%@ internal state change %lu => %lu", self, static_cast<unsigned long>(lastState), static_cast<unsigned long>(state));
@@ -1201,7 +1297,7 @@
[self _stopConnectivityMonitoring];
// reset subscription attempt wait time when subscription succeeds
- _lastSubscriptionAttemptWait = 0;
+ [self _setLastSubscriptionAttemptWait:0];
auto initialSubscribeStart = _initialSubscribeStart;
// We no longer need to track subscribe latency for this device.
@@ -1367,6 +1463,10 @@
// former case we recently had a subscription and do not want to be forcing
// retries immediately.
_lastSubscriptionFailureTime = [NSDate now];
+ {
+ std::lock_guard lock(_descriptionLock);
+ _lastSubscriptionFailureTimeForDescription = _lastSubscriptionFailureTime;
+ }
deviceUsesThread = [self _deviceUsesThread];
@@ -1408,6 +1508,15 @@
[self _doHandleSubscriptionReset:retryDelay];
}
+- (void)_setLastSubscriptionAttemptWait:(uint32_t)lastSubscriptionAttemptWait
+{
+ os_unfair_lock_assert_owner(&_lock);
+ _lastSubscriptionAttemptWait = lastSubscriptionAttemptWait;
+
+ std::lock_guard lock(_descriptionLock);
+ _lastSubscriptionAttemptWaitForDescription = lastSubscriptionAttemptWait;
+}
+
- (void)_doHandleSubscriptionReset:(NSNumber * _Nullable)retryDelay
{
os_unfair_lock_assert_owner(&_lock);
@@ -1417,6 +1526,10 @@
// has given up completely. Those all count as "we have tried and failed to
// subscribe".
_lastSubscriptionFailureTime = [NSDate now];
+ {
+ std::lock_guard lock(_descriptionLock);
+ _lastSubscriptionFailureTimeForDescription = _lastSubscriptionFailureTime;
+ }
// if there is no delegate then also do not retry
if (![self _delegateExists]) {
@@ -1441,16 +1554,17 @@
// counter, so that we don't end up waiting for a long time if the next
// attempt fails for some reason, and retry after whatever time period
// the device told us to use.
- _lastSubscriptionAttemptWait = 0;
+ [self _setLastSubscriptionAttemptWait:0];
secondsToWait = retryDelay.doubleValue;
MTR_LOG("%@ resetting resubscribe attempt counter, and delaying by the server-provided delay: %f",
self, secondsToWait);
} else {
- _lastSubscriptionAttemptWait *= 2;
- if (_lastSubscriptionAttemptWait > MTRDEVICE_SUBSCRIPTION_ATTEMPT_MAX_WAIT_SECONDS) {
- _lastSubscriptionAttemptWait = MTRDEVICE_SUBSCRIPTION_ATTEMPT_MAX_WAIT_SECONDS;
+ auto lastSubscriptionAttemptWait = _lastSubscriptionAttemptWait * 2;
+ if (lastSubscriptionAttemptWait > MTRDEVICE_SUBSCRIPTION_ATTEMPT_MAX_WAIT_SECONDS) {
+ lastSubscriptionAttemptWait = MTRDEVICE_SUBSCRIPTION_ATTEMPT_MAX_WAIT_SECONDS;
}
- secondsToWait = _lastSubscriptionAttemptWait;
+ [self _setLastSubscriptionAttemptWait:lastSubscriptionAttemptWait];
+ secondsToWait = lastSubscriptionAttemptWait;
}
MTR_LOG("%@ scheduling to reattempt subscription in %f seconds", self, secondsToWait);
@@ -1665,6 +1779,9 @@
- (void)unitTestSetMostRecentReportTimes:(NSMutableArray<NSDate *> *)mostRecentReportTimes
{
_mostRecentReportTimes = mostRecentReportTimes;
+
+ std::lock_guard lock(_descriptionLock);
+ _mostRecentReportTimeForDescription = [mostRecentReportTimes lastObject];
}
#endif
@@ -1719,6 +1836,11 @@
}
[_mostRecentReportTimes addObject:[NSDate now]];
+ {
+ std::lock_guard lock(_descriptionLock);
+ _mostRecentReportTimeForDescription = [_mostRecentReportTimes lastObject];
+ }
+
// Calculate running average and update multiplier - need at least 2 items to calculate intervals
if (_mostRecentReportTimes.count > 2) {
NSTimeInterval cumulativeIntervals = 0;
@@ -1784,6 +1906,10 @@
_clusterDataPersistenceFirstScheduledTime = nil;
_mostRecentReportTimes = nil;
+ {
+ std::lock_guard lock(_descriptionLock);
+ _mostRecentReportTimeForDescription = nil;
+ }
_deviceReportingExcessivelyStartTime = nil;
_reportToPersistenceDelayCurrentMultiplier = 1;
@@ -2236,6 +2362,10 @@
[clusterData storeValue:value forAttribute:path.attribute];
+ if ([self _attributePathAffectsDescriptionData:path]) {
+ [self _updateAttributeDependentDescriptionData];
+ }
+
if (value != nil
&& isFromSubscription
&& !_receivingPrimingReport
@@ -2295,10 +2425,11 @@
- (void)_setupConnectivityMonitoring
{
#if ENABLE_CONNECTIVITY_MONITORING
- // Dispatch to own queue first to avoid deadlock with syncGetCompressedFabricID
+ // Dispatch to own queue because we used to need to do that to get the compressedFabricID, but
+ // at this point that's not really needed anymore.
dispatch_async(self.queue, ^{
// Get the required info before setting up the connectivity monitor
- NSNumber * compressedFabricID = [self->_deviceController syncGetCompressedFabricID];
+ NSNumber * compressedFabricID = [self->_deviceController compressedFabricID];
if (!compressedFabricID) {
MTR_LOG_ERROR("%@ could not get compressed fabricID", self);
return;
@@ -3652,7 +3783,7 @@
if (!_deviceConfigurationChanged) {
_deviceConfigurationChanged = [self _attributeAffectsDeviceConfiguration:attributePath];
if (_deviceConfigurationChanged) {
- MTR_LOG("Device configuration changed due to changes in attribute %@", attributePath);
+ MTR_LOG("%@ device configuration changed due to changes in attribute %@", self, attributePath);
}
}
@@ -3761,6 +3892,8 @@
[_persistedClusterData setObject:clusterData[clusterPath] forKey:clusterPath];
}
+ [self _updateAttributeDependentDescriptionData];
+
// 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;
@@ -4104,6 +4237,10 @@
{
auto * cachedData = [self _cachedAttributeValueForPath:attributePath];
+ if (cachedData == nil) {
+ return nil;
+ }
+
auto * attrReport = [[MTRAttributeReport alloc] initWithResponseValue:@{
MTRAttributePathKey : attributePath,
MTRDataKey : cachedData,
@@ -4133,6 +4270,8 @@
- (void)_addInformationalAttributesToCurrentMetricScope
{
+ os_unfair_lock_assert_owner(&self->_lock);
+
using namespace chip::Tracing::DarwinFramework;
MATTER_LOG_METRIC(kMetricDeviceVendorID, [self _informationalVendorID].unsignedShortValue);
MATTER_LOG_METRIC(kMetricDeviceProductID, [self _informationalProductID].unsignedShortValue);
@@ -4140,6 +4279,89 @@
MATTER_LOG_METRIC(kMetricDeviceUsesThread, usesThread);
}
+#pragma mark - Description handling
+
+- (BOOL)_attributePathAffectsDescriptionData:(MTRAttributePath *)path
+{
+ // Technically this does not need to be called while locked, but in
+ // practice it is, and we want to make sure it's clear that this function
+ // should never start taking our data lock.
+ os_unfair_lock_assert_owner(&_lock);
+
+ switch (path.cluster.unsignedLongLongValue) {
+ case MTRClusterIDTypeBasicInformationID: {
+ switch (path.attribute.unsignedLongLongValue) {
+ case MTRAttributeIDTypeClusterBasicInformationAttributeVendorIDID:
+ case MTRAttributeIDTypeClusterBasicInformationAttributeProductIDID:
+ return YES;
+ default:
+ return NO;
+ }
+ }
+ case MTRClusterIDTypeNetworkCommissioningID: {
+ return path.attribute.unsignedLongLongValue == MTRAttributeIDTypeGlobalAttributeFeatureMapID;
+ }
+ default:
+ return NO;
+ }
+}
+
+- (void)_updateAttributeDependentDescriptionData
+{
+ os_unfair_lock_assert_owner(&_lock);
+
+ NSNumber * _Nullable vid = [self _informationalVendorID];
+ NSNumber * _Nullable pid = [self _informationalProductID];
+ NSNumber * _Nullable networkFeatures = [self _networkFeatures];
+
+ std::lock_guard lock(_descriptionLock);
+ _vid = vid;
+ _pid = pid;
+ _allNetworkFeatures = networkFeatures;
+}
+
+- (NSArray<NSNumber *> *)_endpointList
+{
+ os_unfair_lock_assert_owner(&_lock);
+
+ auto * partsListPath = [MTRAttributePath attributePathWithEndpointID:@(kRootEndpointId)
+ clusterID:@(MTRClusterIDTypeDescriptorID)
+ attributeID:@(MTRAttributeIDTypeClusterDescriptorAttributePartsListID)];
+ auto * partsList = [self _cachedAttributeValueForPath:partsListPath];
+ NSMutableArray<NSNumber *> * endpointsOnDevice = [self arrayOfNumbersFromAttributeValue:partsList];
+ if (!endpointsOnDevice) {
+ endpointsOnDevice = [[NSMutableArray<NSNumber *> alloc] init];
+ }
+ // Add Root node!
+ [endpointsOnDevice addObject:@(0)];
+ return endpointsOnDevice;
+}
+
+- (NSNumber * _Nullable)_networkFeatures
+{
+ NSNumber * _Nullable result = nil;
+ auto * endpoints = [self _endpointList];
+ for (NSNumber * endpoint in endpoints) {
+ auto * featureMapPath = [MTRAttributePath attributePathWithEndpointID:endpoint
+ clusterID:@(MTRClusterIDTypeNetworkCommissioningID)
+ attributeID:@(MTRAttributeIDTypeGlobalAttributeFeatureMapID)];
+ auto * featureMap = [self _informationalNumberAtAttributePath:featureMapPath];
+ if (featureMap == nil) {
+ // No network commissioning cluster on this endpoint, or no known
+ // FeatureMap attribute value for it yet.
+ continue;
+ }
+
+ if (result == nil) {
+ result = featureMap;
+ } else {
+ result = @(featureMap.unsignedLongLongValue | result.unsignedLongLongValue);
+ }
+ }
+
+ return result;
+}
+
@end
/* BEGIN DRAGONS: Note methods here cannot be renamed, and are used by private callers, do not rename, remove or modify behavior here */
diff --git a/src/darwin/Framework/CHIP/MTRDeviceController.mm b/src/darwin/Framework/CHIP/MTRDeviceController.mm
index 6c312d5..25a0e7d 100644
--- a/src/darwin/Framework/CHIP/MTRDeviceController.mm
+++ b/src/darwin/Framework/CHIP/MTRDeviceController.mm
@@ -75,6 +75,7 @@
#include <atomic>
#include <dns_sd.h>
+#include <optional>
#include <string>
#import <os/lock.h>
@@ -107,8 +108,9 @@
using namespace chip::Tracing::DarwinFramework;
@implementation MTRDeviceController {
- // Atomic because it can be touched from multiple threads.
+ // Atomic because they can be touched from multiple threads.
std::atomic<chip::FabricIndex> _storedFabricIndex;
+ std::atomic<std::optional<uint64_t>> _storedCompressedFabricID;
// queue used to serialize all work performed by the MTRDeviceController
dispatch_queue_t _chipWorkQueue;
@@ -278,6 +280,7 @@
_concurrentSubscriptionPool = [[MTRAsyncWorkQueue alloc] initWithContext:self width:concurrentSubscriptionPoolSize];
_storedFabricIndex = chip::kUndefinedFabricIndex;
+ _storedCompressedFabricID = std::nullopt;
_storageBehaviorConfiguration = storageBehaviorConfiguration;
}
@@ -351,6 +354,7 @@
// shutdown completes, in case it wants to write to storage as it
// shuts down.
_storedFabricIndex = chip::kUndefinedFabricIndex;
+ _storedCompressedFabricID = std::nullopt;
delete commissionerToShutDown;
if (_operationalCredentialsDelegate != nil) {
_operationalCredentialsDelegate->SetDeviceCommissioner(nullptr);
@@ -590,6 +594,7 @@
}
self->_storedFabricIndex = fabricIdx;
+ self->_storedCompressedFabricID = _cppCommissioner->GetCompressedFabricId();
commissionerInitialized = YES;
MTR_LOG("%@ startup succeeded for nodeID 0x%016llX", self, self->_cppCommissioner->GetNodeId());
@@ -1440,20 +1445,8 @@
- (nullable NSNumber *)compressedFabricID
{
- assertChipStackLockedByCurrentThread();
-
- if (!_cppCommissioner) {
- return nil;
- }
-
- return @(_cppCommissioner->GetCompressedFabricId());
-}
-
-- (NSNumber * _Nullable)syncGetCompressedFabricID
-{
- return [self syncRunOnWorkQueueWithReturnValue:^NSNumber * {
- return [self compressedFabricID];
- } error:nil];
+ auto storedValue = _storedCompressedFabricID.load();
+ return storedValue.has_value() ? @(storedValue.value()) : nil;
}
- (CHIP_ERROR)isRunningOnFabric:(chip::FabricTable *)fabricTable
diff --git a/src/darwin/Framework/CHIP/MTRDeviceController_Internal.h b/src/darwin/Framework/CHIP/MTRDeviceController_Internal.h
index 925bbb2..479dd85 100644
--- a/src/darwin/Framework/CHIP/MTRDeviceController_Internal.h
+++ b/src/darwin/Framework/CHIP/MTRDeviceController_Internal.h
@@ -79,8 +79,6 @@
/**
* Will return the compressed fabric id of the fabric if the controller is
* running, else nil.
- *
- * This property MUST be gotten from the Matter work queue.
*/
@property (nonatomic, readonly, nullable) NSNumber * compressedFabricID;
@@ -266,8 +264,6 @@
- (MTRDevice *)deviceForNodeID:(NSNumber *)nodeID;
- (void)removeDevice:(MTRDevice *)device;
-- (NSNumber * _Nullable)syncGetCompressedFabricID;
-
/**
* Since getSessionForNode now enqueues by the subscription pool for Thread
* devices, MTRDevice needs a direct non-queued access because it already
diff --git a/src/darwin/Framework/CHIP/MTRDevice_Concrete.mm b/src/darwin/Framework/CHIP/MTRDevice_Concrete.mm
index a90b49d..e22b0b8 100644
--- a/src/darwin/Framework/CHIP/MTRDevice_Concrete.mm
+++ b/src/darwin/Framework/CHIP/MTRDevice_Concrete.mm
@@ -219,6 +219,24 @@
{
return state == MTRInternalDeviceStateInitialSubscriptionEstablished || state == MTRInternalDeviceStateLaterSubscriptionEstablished;
}
+
+NSString * InternalDeviceStateString(MTRInternalDeviceState state)
+{
+ switch (state) {
+ case MTRInternalDeviceStateUnsubscribed:
+ return @"Unsubscribed";
+ case MTRInternalDeviceStateSubscribing:
+ return @"Subscribing";
+ case MTRInternalDeviceStateInitialSubscriptionEstablished:
+ return @"InitialSubscriptionEstablished";
+ case MTRInternalDeviceStateResubscribing:
+ return @"Resubscribing";
+ case MTRInternalDeviceStateLaterSubscriptionEstablished:
+ return @"LaterSubscriptionEstablished";
+ default:
+ return @"Unknown";
+ }
+}
} // anonymous namespace
typedef NS_ENUM(NSUInteger, MTRDeviceExpectedValueFieldIndex) {
@@ -265,8 +283,11 @@
@interface MTRDevice_Concrete ()
@property (nonatomic, readonly) os_unfair_lock lock; // protects the caches and device state
// protects against concurrent time updates by guarding timeUpdateScheduled flag which manages time updates scheduling,
-// and protects device calls to setUTCTime and setDSTOffset
+// and protects device calls to setUTCTime and setDSTOffset. This can't just be replaced with "lock", because the time
+// update code calls public APIs like readAttributeWithEndpointID:.. (which attempt to take "lock") while holding
+// whatever lock protects the time sync bits.
@property (nonatomic, readonly) os_unfair_lock timeSyncLock;
+
@property (nonatomic) chip::FabricIndex fabricIndex;
@property (nonatomic) NSMutableArray<NSDictionary<NSString *, id> *> * unreportedEvents;
@property (nonatomic) BOOL receivingReport;
@@ -392,6 +413,27 @@
id _systemTimeChangeObserverToken;
NSMutableSet<MTRDeviceDelegateInfo_ConcreteCopy *> * _delegates;
+
+ // Protects mutable state used by our description getter. This is a separate lock from "lock"
+ // so that we don't need to worry about getting our description while holding "lock" (e.g due to
+ // logging self). This lock _must_ be held narrowly, with no other lock acquisitions allowed
+ // while it's held, to avoid deadlock.
+ os_unfair_lock _descriptionLock;
+
+ // State used by our description getter: access to these must be protected by descriptionLock.
+ NSNumber * _Nullable _vid; // nil if unknown
+ NSNumber * _Nullable _pid; // nil if unknown
+ // _allNetworkFeatures is a bitwise or of the feature maps of all network commissioning clusters
+ // present on the device, or nil if there aren't any.
+ NSNumber * _Nullable _allNetworkFeatures;
+ // Copy of _internalDeviceState that is safe to use in description.
+ MTRInternalDeviceState _internalDeviceStateForDescription;
+ // Copy of _lastSubscriptionAttemptWait that is safe to use in description.
+ uint32_t _lastSubscriptionAttemptWaitForDescription;
+ // Most recent entry in _mostRecentReportTimes, if any.
+ NSDate * _Nullable _mostRecentReportTimeForDescription;
+ // Copy of _lastSubscriptionFailureTime that is safe to use in description.
+ NSDate * _Nullable _lastSubscriptionFailureTimeForDescription;
}
// synthesize superclass property readwrite accessors
@@ -411,6 +453,7 @@
if (self = [super initForSubclasses]) {
_lock = OS_UNFAIR_LOCK_INIT;
_timeSyncLock = OS_UNFAIR_LOCK_INIT;
+ _descriptionLock = OS_UNFAIR_LOCK_INIT;
_nodeID = [nodeID copy];
_fabricIndex = controller.fabricIndex;
_deviceController = controller;
@@ -420,6 +463,7 @@
_asyncWorkQueue = [[MTRAsyncWorkQueue alloc] initWithContext:self];
_state = MTRDeviceStateUnknown;
_internalDeviceState = MTRInternalDeviceStateUnsubscribed;
+ _internalDeviceStateForDescription = MTRInternalDeviceStateUnsubscribed;
if (controller.controllerDataStore) {
_persistedClusterData = [[NSCache alloc] init];
} else {
@@ -456,8 +500,58 @@
- (NSString *)description
{
+ id _Nullable vid;
+ id _Nullable pid;
+ NSNumber * _Nullable networkFeatures;
+ MTRInternalDeviceState internalDeviceState;
+ uint32_t lastSubscriptionAttemptWait;
+ NSDate * _Nullable mostRecentReportTime;
+ NSDate * _Nullable lastSubscriptionFailureTime;
+ {
+ std::lock_guard lock(_descriptionLock);
+ vid = _vid;
+ pid = _pid;
+ networkFeatures = _allNetworkFeatures;
+ internalDeviceState = _internalDeviceStateForDescription;
+ lastSubscriptionAttemptWait = _lastSubscriptionAttemptWaitForDescription;
+ mostRecentReportTime = _mostRecentReportTimeForDescription;
+ lastSubscriptionFailureTime = _lastSubscriptionFailureTimeForDescription;
+ }
+
+ if (vid == nil) {
+ vid = @"Unknown";
+ }
+
+ if (pid == nil) {
+ pid = @"Unknown";
+ }
+
+ NSString * wifi;
+ NSString * thread;
+ if (networkFeatures == nil) {
+ wifi = @"NO";
+ thread = @"NO";
+ } else {
+ wifi = YES_NO(networkFeatures.unsignedLongLongValue & MTRNetworkCommissioningFeatureWiFiNetworkInterface);
+ thread = YES_NO(networkFeatures.unsignedLongLongValue & MTRNetworkCommissioningFeatureThreadNetworkInterface);
+ }
+
+ NSString * reportAge;
+ if (mostRecentReportTime) {
+ reportAge = [NSString stringWithFormat:@" (%.0lfs ago)", -[mostRecentReportTime timeIntervalSinceNow]];
+ } else {
+ reportAge = @"";
+ }
+
+ NSString * subscriptionFailureAge;
+ if (lastSubscriptionFailureTime) {
+ subscriptionFailureAge = [NSString stringWithFormat:@" (%.0lfs ago)", -[lastSubscriptionFailureTime timeIntervalSinceNow]];
+ } else {
+ subscriptionFailureAge = @"";
+ }
+
return [NSString
- stringWithFormat:@"<MTRDevice: %p>[fabric: %u, nodeID: 0x%016llX]", self, _fabricIndex, _nodeID.unsignedLongLongValue];
+ stringWithFormat:@"<MTRDevice: %p, node: %016llX-%016llX (%llu), VID: %@, PID: %@, WiFi: %@, Thread: %@, state: %@, last subscription attempt wait: %lus, queued work: %lu, last report: %@%@, last subscription failure: %@%@, controller: %@>", self, _deviceController.compressedFabricID.unsignedLongLongValue, _nodeID.unsignedLongLongValue, _nodeID.unsignedLongLongValue, vid, pid, wifi, thread, InternalDeviceStateString(internalDeviceState), static_cast<unsigned long>(lastSubscriptionAttemptWait), static_cast<unsigned long>(_asyncWorkQueue.itemCount), mostRecentReportTime, reportAge, lastSubscriptionFailureTime, subscriptionFailureAge, _deviceController.uniqueIdentifier];
}
+ (MTRDevice *)deviceWithNodeID:(NSNumber *)nodeID controller:(MTRDeviceController *)controller
@@ -574,13 +668,11 @@
- (NSArray<NSNumber *> *)_endpointsWithTimeSyncClusterServer
{
- auto partsList = [self readAttributeWithEndpointID:@(0) clusterID:@(MTRClusterIDTypeDescriptorID) attributeID:@(MTRAttributeIDTypeClusterDescriptorAttributePartsListID) params:nil];
- NSMutableArray<NSNumber *> * endpointsOnDevice = [self arrayOfNumbersFromAttributeValue:partsList];
- if (!endpointsOnDevice) {
- endpointsOnDevice = [[NSMutableArray<NSNumber *> alloc] init];
+ NSArray<NSNumber *> * endpointsOnDevice;
+ {
+ std::lock_guard lock(_lock);
+ endpointsOnDevice = [self _endpointList];
}
- // Add Root node!
- [endpointsOnDevice addObject:@(0)];
NSMutableArray<NSNumber *> * endpointsWithTimeSyncCluster = [[NSMutableArray<NSNumber *> alloc] init];
for (NSNumber * endpoint in endpointsOnDevice) {
@@ -1073,6 +1165,10 @@
os_unfair_lock_assert_owner(&self->_lock);
MTRInternalDeviceState lastState = _internalDeviceState;
_internalDeviceState = state;
+ {
+ std::lock_guard lock(_descriptionLock);
+ _internalDeviceStateForDescription = _internalDeviceState;
+ }
if (lastState != state) {
MTR_LOG("%@ internal state change %lu => %lu", self, static_cast<unsigned long>(lastState), static_cast<unsigned long>(state));
@@ -1114,7 +1210,7 @@
[self _stopConnectivityMonitoring];
// reset subscription attempt wait time when subscription succeeds
- _lastSubscriptionAttemptWait = 0;
+ [self _setLastSubscriptionAttemptWait:0];
auto initialSubscribeStart = _initialSubscribeStart;
// We no longer need to track subscribe latency for this device.
@@ -1280,6 +1376,10 @@
// former case we recently had a subscription and do not want to be forcing
// retries immediately.
_lastSubscriptionFailureTime = [NSDate now];
+ {
+ std::lock_guard lock(_descriptionLock);
+ _lastSubscriptionFailureTimeForDescription = _lastSubscriptionFailureTime;
+ }
deviceUsesThread = [self _deviceUsesThread];
@@ -1321,6 +1421,15 @@
[self _doHandleSubscriptionReset:retryDelay];
}
+- (void)_setLastSubscriptionAttemptWait:(uint32_t)lastSubscriptionAttemptWait
+{
+ os_unfair_lock_assert_owner(&_lock);
+ _lastSubscriptionAttemptWait = lastSubscriptionAttemptWait;
+
+ std::lock_guard lock(_descriptionLock);
+ _lastSubscriptionAttemptWaitForDescription = lastSubscriptionAttemptWait;
+}
+
- (void)_doHandleSubscriptionReset:(NSNumber * _Nullable)retryDelay
{
os_unfair_lock_assert_owner(&_lock);
@@ -1330,6 +1439,10 @@
// has given up completely. Those all count as "we have tried and failed to
// subscribe".
_lastSubscriptionFailureTime = [NSDate now];
+ {
+ std::lock_guard lock(_descriptionLock);
+ _lastSubscriptionFailureTimeForDescription = _lastSubscriptionFailureTime;
+ }
// if there is no delegate then also do not retry
if (![self _delegateExists]) {
@@ -1354,16 +1467,17 @@
// counter, so that we don't end up waiting for a long time if the next
// attempt fails for some reason, and retry after whatever time period
// the device told us to use.
- _lastSubscriptionAttemptWait = 0;
+ [self _setLastSubscriptionAttemptWait:0];
secondsToWait = retryDelay.doubleValue;
MTR_LOG("%@ resetting resubscribe attempt counter, and delaying by the server-provided delay: %f",
self, secondsToWait);
} else {
- _lastSubscriptionAttemptWait *= 2;
- if (_lastSubscriptionAttemptWait > MTRDEVICE_SUBSCRIPTION_ATTEMPT_MAX_WAIT_SECONDS) {
- _lastSubscriptionAttemptWait = MTRDEVICE_SUBSCRIPTION_ATTEMPT_MAX_WAIT_SECONDS;
+ auto lastSubscriptionAttemptWait = _lastSubscriptionAttemptWait * 2;
+ if (lastSubscriptionAttemptWait > MTRDEVICE_SUBSCRIPTION_ATTEMPT_MAX_WAIT_SECONDS) {
+ lastSubscriptionAttemptWait = MTRDEVICE_SUBSCRIPTION_ATTEMPT_MAX_WAIT_SECONDS;
}
- secondsToWait = _lastSubscriptionAttemptWait;
+ [self _setLastSubscriptionAttemptWait:lastSubscriptionAttemptWait];
+ secondsToWait = lastSubscriptionAttemptWait;
}
MTR_LOG("%@ scheduling to reattempt subscription in %f seconds", self, secondsToWait);
@@ -1578,6 +1692,9 @@
- (void)unitTestSetMostRecentReportTimes:(NSMutableArray<NSDate *> *)mostRecentReportTimes
{
_mostRecentReportTimes = mostRecentReportTimes;
+
+ std::lock_guard lock(_descriptionLock);
+ _mostRecentReportTimeForDescription = [mostRecentReportTimes lastObject];
}
#endif
@@ -1632,6 +1749,11 @@
}
[_mostRecentReportTimes addObject:[NSDate now]];
+ {
+ std::lock_guard lock(_descriptionLock);
+ _mostRecentReportTimeForDescription = [_mostRecentReportTimes lastObject];
+ }
+
// Calculate running average and update multiplier - need at least 2 items to calculate intervals
if (_mostRecentReportTimes.count > 2) {
NSTimeInterval cumulativeIntervals = 0;
@@ -1697,6 +1819,10 @@
_clusterDataPersistenceFirstScheduledTime = nil;
_mostRecentReportTimes = nil;
+ {
+ std::lock_guard lock(_descriptionLock);
+ _mostRecentReportTimeForDescription = nil;
+ }
_deviceReportingExcessivelyStartTime = nil;
_reportToPersistenceDelayCurrentMultiplier = 1;
@@ -2149,6 +2275,10 @@
[clusterData storeValue:value forAttribute:path.attribute];
+ if ([self _attributePathAffectsDescriptionData:path]) {
+ [self _updateAttributeDependentDescriptionData];
+ }
+
if (value != nil
&& isFromSubscription
&& !_receivingPrimingReport
@@ -2208,10 +2338,11 @@
- (void)_setupConnectivityMonitoring
{
#if ENABLE_CONNECTIVITY_MONITORING
- // Dispatch to own queue first to avoid deadlock with syncGetCompressedFabricID
+ // Dispatch to own queue because we used to need to do that to get the compressedFabricID, but
+ // at this point that's not really needed anymore.
dispatch_async(self.queue, ^{
// Get the required info before setting up the connectivity monitor
- NSNumber * compressedFabricID = [self->_deviceController syncGetCompressedFabricID];
+ NSNumber * compressedFabricID = [self->_deviceController compressedFabricID];
if (!compressedFabricID) {
MTR_LOG_ERROR("%@ could not get compressed fabricID", self);
return;
@@ -3565,7 +3696,7 @@
if (!_deviceConfigurationChanged) {
_deviceConfigurationChanged = [self _attributeAffectsDeviceConfiguration:attributePath];
if (_deviceConfigurationChanged) {
- MTR_LOG("Device configuration changed due to changes in attribute %@", attributePath);
+ MTR_LOG("%@ device configuration changed due to changes in attribute %@", self, attributePath);
}
}
@@ -3674,6 +3805,8 @@
[_persistedClusterData setObject:clusterData[clusterPath] forKey:clusterPath];
}
+ [self _updateAttributeDependentDescriptionData];
+
// 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;
@@ -4017,6 +4150,10 @@
{
auto * cachedData = [self _cachedAttributeValueForPath:attributePath];
+ if (cachedData == nil) {
+ return nil;
+ }
+
auto * attrReport = [[MTRAttributeReport alloc] initWithResponseValue:@{
MTRAttributePathKey : attributePath,
MTRDataKey : cachedData,
@@ -4046,6 +4183,8 @@
- (void)_addInformationalAttributesToCurrentMetricScope
{
+ os_unfair_lock_assert_owner(&self->_lock);
+
using namespace chip::Tracing::DarwinFramework;
MATTER_LOG_METRIC(kMetricDeviceVendorID, [self _informationalVendorID].unsignedShortValue);
MATTER_LOG_METRIC(kMetricDeviceProductID, [self _informationalProductID].unsignedShortValue);
@@ -4053,6 +4192,89 @@
MATTER_LOG_METRIC(kMetricDeviceUsesThread, usesThread);
}
+#pragma mark - Description handling
+
+- (BOOL)_attributePathAffectsDescriptionData:(MTRAttributePath *)path
+{
+ // Technically this does not need to be called while locked, but in
+ // practice it is, and we want to make sure it's clear that this function
+ // should never start taking our data lock.
+ os_unfair_lock_assert_owner(&_lock);
+
+ switch (path.cluster.unsignedLongLongValue) {
+ case MTRClusterIDTypeBasicInformationID: {
+ switch (path.attribute.unsignedLongLongValue) {
+ case MTRAttributeIDTypeClusterBasicInformationAttributeVendorIDID:
+ case MTRAttributeIDTypeClusterBasicInformationAttributeProductIDID:
+ return YES;
+ default:
+ return NO;
+ }
+ }
+ case MTRClusterIDTypeNetworkCommissioningID: {
+ return path.attribute.unsignedLongLongValue == MTRAttributeIDTypeGlobalAttributeFeatureMapID;
+ }
+ default:
+ return NO;
+ }
+}
+
+- (void)_updateAttributeDependentDescriptionData
+{
+ os_unfair_lock_assert_owner(&_lock);
+
+ NSNumber * _Nullable vid = [self _informationalVendorID];
+ NSNumber * _Nullable pid = [self _informationalProductID];
+ NSNumber * _Nullable networkFeatures = [self _networkFeatures];
+
+ std::lock_guard lock(_descriptionLock);
+ _vid = vid;
+ _pid = pid;
+ _allNetworkFeatures = networkFeatures;
+}
+
+- (NSArray<NSNumber *> *)_endpointList
+{
+ os_unfair_lock_assert_owner(&_lock);
+
+ auto * partsListPath = [MTRAttributePath attributePathWithEndpointID:@(kRootEndpointId)
+ clusterID:@(MTRClusterIDTypeDescriptorID)
+ attributeID:@(MTRAttributeIDTypeClusterDescriptorAttributePartsListID)];
+ auto * partsList = [self _cachedAttributeValueForPath:partsListPath];
+ NSMutableArray<NSNumber *> * endpointsOnDevice = [self arrayOfNumbersFromAttributeValue:partsList];
+ if (!endpointsOnDevice) {
+ endpointsOnDevice = [[NSMutableArray<NSNumber *> alloc] init];
+ }
+ // Add Root node!
+ [endpointsOnDevice addObject:@(0)];
+ return endpointsOnDevice;
+}
+
+- (NSNumber * _Nullable)_networkFeatures
+{
+ NSNumber * _Nullable result = nil;
+ auto * endpoints = [self _endpointList];
+ for (NSNumber * endpoint in endpoints) {
+ auto * featureMapPath = [MTRAttributePath attributePathWithEndpointID:endpoint
+ clusterID:@(MTRClusterIDTypeNetworkCommissioningID)
+ attributeID:@(MTRAttributeIDTypeGlobalAttributeFeatureMapID)];
+ auto * featureMap = [self _informationalNumberAtAttributePath:featureMapPath];
+ if (featureMap == nil) {
+ // No network commissioning cluster on this endpoint, or no known
+ // FeatureMap attribute value for it yet.
+ continue;
+ }
+
+ if (result == nil) {
+ result = featureMap;
+ } else {
+ result = @(featureMap.unsignedLongLongValue | result.unsignedLongLongValue);
+ }
+ }
+
+ return result;
+}
+
@end
/* BEGIN DRAGONS: Note methods here cannot be renamed, and are used by private callers, do not rename, remove or modify behavior here */
