diff --git a/src/darwin/Framework/CHIP/MTRDevice.mm b/src/darwin/Framework/CHIP/MTRDevice.mm index a7aa7645185a7c..f2ba2d2173e977 100644 --- a/src/darwin/Framework/CHIP/MTRDevice.mm +++ b/src/darwin/Framework/CHIP/MTRDevice.mm @@ -284,6 +284,8 @@ - (void)invalidate os_unfair_lock_lock(&self->_lock); + _state = MTRDeviceStateUnknown; + _weakDelegate = nil; // Make sure we don't try to resubscribe if we have a pending resubscribe @@ -343,13 +345,13 @@ - (void)_changeState:(MTRDeviceState)state _state = state; if (lastState != state) { if (state != MTRDeviceStateReachable) { - MTR_LOG_INFO("%@ State change %lu => %lu, set estimated start time to nil", self, static_cast(lastState), + MTR_LOG_INFO("%@ reachability state change %lu => %lu, set estimated start time to nil", self, static_cast(lastState), static_cast(state)); _estimatedStartTime = nil; _estimatedStartTimeFromGeneralDiagnosticsUpTime = nil; } else { MTR_LOG_INFO( - "%@ State change %lu => %lu", self, static_cast(lastState), static_cast(state)); + "%@ reachability state change %lu => %lu", self, static_cast(lastState), static_cast(state)); } id delegate = _weakDelegate.strongObject; if (delegate) { @@ -357,6 +359,9 @@ - (void)_changeState:(MTRDeviceState)state [delegate device:self stateChanged:state]; }); } + } else { + MTR_LOG_INFO( + "%@ Not reporting reachability state change, since no change in state %lu => %lu", self, static_cast(lastState), static_cast(state)); } } @@ -592,14 +597,14 @@ - (void)_handleEventReport:(NSArray *> *)eventRepor // If event time is of MTREventTimeTypeSystemUpTime type, then update estimated start time as needed NSNumber * eventTimeTypeNumber = eventDict[MTREventTimeTypeKey]; if (!eventTimeTypeNumber) { - MTR_LOG_ERROR("Event %@ missing event time type", eventDict); + MTR_LOG_ERROR("%@ Event %@ missing event time type", self, eventDict); continue; } MTREventTimeType eventTimeType = (MTREventTimeType) eventTimeTypeNumber.unsignedIntegerValue; if (eventTimeType == MTREventTimeTypeSystemUpTime) { NSNumber * eventTimeValueNumber = eventDict[MTREventSystemUpTimeKey]; if (!eventTimeValueNumber) { - MTR_LOG_ERROR("Event %@ missing event time value", eventDict); + MTR_LOG_ERROR("%@ Event %@ missing event time value", self, eventDict); continue; } NSTimeInterval eventTimeValue = eventTimeValueNumber.doubleValue; @@ -792,7 +797,7 @@ - (void)_setupSubscription CHIP_ERROR err = readClient->SendAutoResubscribeRequest(std::move(readParams)); if (err != CHIP_NO_ERROR) { - NSError * error = [MTRError errorForCHIPErrorCode:err]; + NSError * error = [MTRError errorForCHIPErrorCode:err logContext:self]; MTR_LOG_ERROR("%@ SendAutoResubscribeRequest error %@", self, error); dispatch_async(self.queue, ^{ [self _handleSubscriptionError:error]; @@ -982,6 +987,8 @@ static BOOL AttributeHasChangesOmittedQuality(MTRAttributePath * attributePath) // Create work item, set ready handler to perform task, then enqueue the work MTRAsyncWorkItem * workItem = [[MTRAsyncWorkItem alloc] initWithQueue:self.queue]; uint64_t workItemID = workItem.uniqueID; // capture only the ID, not the work item + NSNumber * nodeID = [self nodeID]; + [workItem setBatchingID:MTRDeviceWorkItemBatchingReadID data:readRequests handler:^(id opaqueDataCurrent, id opaqueDataNext) { mtr_hide(self); // don't capture self accidentally NSMutableArray * readRequestsCurrent = opaqueDataCurrent; @@ -991,14 +998,14 @@ static BOOL AttributeHasChangesOmittedQuality(MTRAttributePath * attributePath) while (readRequestsNext.count) { // Can only read up to 9 paths at a time, per spec if (readRequestsCurrent.count >= 9) { - MTR_LOG_INFO("Batching read attribute work item [%llu]: cannot add more work, item is full", workItemID); + MTR_LOG_INFO("Batching read attribute work item [%llu]: cannot add more work, item is full [%@:%@:%@:%@]", workItemID, nodeID, endpointID, clusterID, attributeID); return outcome; } // if params don't match then they cannot be merged if (![readRequestsNext[0][MTRDeviceReadRequestFieldParamsIndex] isEqual:readRequestsCurrent[0][MTRDeviceReadRequestFieldParamsIndex]]) { - MTR_LOG_INFO("Batching read attribute work item [%llu]: cannot add more work, parameter mismatch", workItemID); + MTR_LOG_INFO("Batching read attribute work item [%llu]: cannot add more work, parameter mismatch [%@:%@:%@:%@]", workItemID, nodeID, endpointID, clusterID, attributeID); return outcome; } @@ -1006,8 +1013,8 @@ static BOOL AttributeHasChangesOmittedQuality(MTRAttributePath * attributePath) auto readItem = readRequestsNext.firstObject; [readRequestsNext removeObjectAtIndex:0]; [readRequestsCurrent addObject:readItem]; - MTR_LOG_INFO("Batching read attribute work item [%llu]: added %@ (now %tu requests total)", - workItemID, readItem, readRequestsCurrent.count); + MTR_LOG_INFO("Batching read attribute work item [%llu]: added %@ (now %tu requests total) [%@:%@:%@:%@]", + workItemID, readItem, readRequestsCurrent.count, nodeID, endpointID, clusterID, attributeID); outcome = MTRBatchedPartially; } NSCAssert(readRequestsNext.count == 0, @"should have batched everything or returned early"); @@ -1017,7 +1024,7 @@ static BOOL AttributeHasChangesOmittedQuality(MTRAttributePath * attributePath) mtr_hide(self); // don't capture self accidentally for (NSArray * readItem in readRequests) { if ([readItem isEqual:opaqueItemData]) { - MTR_LOG_DEFAULT("Read attribute work item [%llu] report duplicate %@", workItemID, readItem); + MTR_LOG_DEFAULT("Read attribute work item [%llu] report duplicate %@ [%@:%@:%@:%@]", workItemID, readItem, nodeID, endpointID, clusterID, attributeID); *isDuplicate = YES; *stop = YES; return; @@ -1053,23 +1060,23 @@ static BOOL AttributeHasChangesOmittedQuality(MTRAttributePath * attributePath) if (values) { // Since the format is the same data-value dictionary, this looks like an // attribute report - MTR_LOG_INFO("Read attribute work item [%llu] result: %@", workItemID, values); + MTR_LOG_INFO("Read attribute work item [%llu] result: %@ [%@:%@:%@:%@]", workItemID, values, nodeID, endpointID, clusterID, attributeID); [self _handleAttributeReport:values]; } // TODO: better retry logic if (error && (retryCount < 2)) { - MTR_LOG_ERROR("Read attribute work item [%llu] failed (will retry): %@", workItemID, error); + MTR_LOG_ERROR("Read attribute work item [%llu] failed (will retry): %@ [%@:%@:%@:%@]", workItemID, error, nodeID, endpointID, clusterID, attributeID); completion(MTRAsyncWorkNeedsRetry); } else { if (error) { - MTR_LOG_DEFAULT("Read attribute work item [%llu] failed (giving up): %@", workItemID, error); + MTR_LOG_DEFAULT("Read attribute work item [%llu] failed (giving up): %@ [%@:%@:%@:%@]", workItemID, error, nodeID, endpointID, clusterID, attributeID); } completion(MTRAsyncWorkComplete); } }]; }]; - [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"read %@ %@ %@", endpointID, clusterID, attributeID]; + [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"read %@ %@ %@ %@", self.nodeID, endpointID, clusterID, attributeID]; } return attributeValueToReturn; @@ -1137,7 +1144,7 @@ - (void)writeAttributeWithEndpointID:(NSNumber *)endpointID completion(MTRAsyncWorkComplete); }]; }]; - [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"write %@ %@ %@", endpointID, clusterID, attributeID]; + [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"write %@ %@ %@ %@", self.nodeID, endpointID, clusterID, attributeID]; } - (void)invokeCommandWithEndpointID:(NSNumber *)endpointID @@ -1739,7 +1746,7 @@ - (void)setExpectedValues:(NSArray *> *)values NSDate * expirationTime = [NSDate dateWithTimeIntervalSinceNow:expectedValueInterval.doubleValue / 1000]; MTR_LOG_INFO( - "Setting expected values %@ with expiration time %f seconds from now", values, [expirationTime timeIntervalSinceNow]); + "%@ Setting expected values %@ with expiration time %f seconds from now", self, values, [expirationTime timeIntervalSinceNow]); os_unfair_lock_lock(&self->_lock); diff --git a/src/darwin/Framework/CHIP/MTRError.h b/src/darwin/Framework/CHIP/MTRError.h index a2bea3e5a49e40..8eaefbd50df643 100644 --- a/src/darwin/Framework/CHIP/MTRError.h +++ b/src/darwin/Framework/CHIP/MTRError.h @@ -104,31 +104,33 @@ typedef NS_ERROR_ENUM(MTRErrorDomain, MTRErrorCode){ typedef NS_ERROR_ENUM(MTRInteractionErrorDomain, MTRInteractionErrorCode){ // These values come from the general status code table in the Matter // Interaction Model specification. - MTRInteractionErrorCodeFailure = 0x01, - MTRInteractionErrorCodeInvalidSubscription = 0x7d, - MTRInteractionErrorCodeUnsupportedAccess = 0x7e, - MTRInteractionErrorCodeUnsupportedEndpoint = 0x7f, - MTRInteractionErrorCodeInvalidAction = 0x80, - MTRInteractionErrorCodeUnsupportedCommand = 0x81, - MTRInteractionErrorCodeInvalidCommand = 0x85, - MTRInteractionErrorCodeUnsupportedAttribute = 0x86, - MTRInteractionErrorCodeConstraintError = 0x87, - MTRInteractionErrorCodeUnsupportedWrite = 0x88, - MTRInteractionErrorCodeResourceExhausted = 0x89, - MTRInteractionErrorCodeNotFound = 0x8b, - MTRInteractionErrorCodeUnreportableAttribute = 0x8c, - MTRInteractionErrorCodeInvalidDataType = 0x8d, - MTRInteractionErrorCodeUnsupportedRead = 0x8f, - MTRInteractionErrorCodeDataVersionMismatch = 0x92, - MTRInteractionErrorCodeTimeout = 0x94, - MTRInteractionErrorCodeBusy = 0x9c, - MTRInteractionErrorCodeUnsupportedCluster = 0xc3, - MTRInteractionErrorCodeNoUpstreamSubscription = 0xc5, - MTRInteractionErrorCodeNeedsTimedInteraction = 0xc6, - MTRInteractionErrorCodeUnsupportedEvent = 0xc7, - MTRInteractionErrorCodePathsExhausted = 0xc8, - MTRInteractionErrorCodeTimedRequestMismatch = 0xc9, - MTRInteractionErrorCodeFailsafeRequired = 0xca, + MTRInteractionErrorCodeFailure = 0x01, + MTRInteractionErrorCodeInvalidSubscription = 0x7d, + MTRInteractionErrorCodeUnsupportedAccess = 0x7e, + MTRInteractionErrorCodeUnsupportedEndpoint = 0x7f, + MTRInteractionErrorCodeInvalidAction = 0x80, + MTRInteractionErrorCodeUnsupportedCommand = 0x81, + MTRInteractionErrorCodeInvalidCommand = 0x85, + MTRInteractionErrorCodeUnsupportedAttribute = 0x86, + MTRInteractionErrorCodeConstraintError = 0x87, + MTRInteractionErrorCodeUnsupportedWrite = 0x88, + MTRInteractionErrorCodeResourceExhausted = 0x89, + MTRInteractionErrorCodeNotFound = 0x8b, + MTRInteractionErrorCodeUnreportableAttribute = 0x8c, + MTRInteractionErrorCodeInvalidDataType = 0x8d, + MTRInteractionErrorCodeUnsupportedRead = 0x8f, + MTRInteractionErrorCodeDataVersionMismatch = 0x92, + MTRInteractionErrorCodeTimeout = 0x94, + MTRInteractionErrorCodeBusy = 0x9c, + MTRInteractionErrorCodeUnsupportedCluster = 0xc3, + MTRInteractionErrorCodeNoUpstreamSubscription = 0xc5, + MTRInteractionErrorCodeNeedsTimedInteraction = 0xc6, + MTRInteractionErrorCodeUnsupportedEvent = 0xc7, + MTRInteractionErrorCodePathsExhausted = 0xc8, + MTRInteractionErrorCodeTimedRequestMismatch = 0xc9, + MTRInteractionErrorCodeFailsafeRequired = 0xca, + MTRInteractionErrorInvalidInState MTR_NEWLY_AVAILABLE = 0xcb, + MTRInteractionErrorNoCommandResponse MTR_NEWLY_AVAILABLE = 0xcc, }; // clang-format on diff --git a/src/darwin/Framework/CHIP/MTRError.mm b/src/darwin/Framework/CHIP/MTRError.mm index c2c02f6a74b207..0cb40006ac3293 100644 --- a/src/darwin/Framework/CHIP/MTRError.mm +++ b/src/darwin/Framework/CHIP/MTRError.mm @@ -44,12 +44,17 @@ - (instancetype)initWithError:(CHIP_ERROR)error; @implementation MTRError + (NSError *)errorForCHIPErrorCode:(CHIP_ERROR)errorCode +{ + return [MTRError errorForCHIPErrorCode:errorCode logContext:nil]; +} + ++ (NSError *)errorForCHIPErrorCode:(CHIP_ERROR)errorCode logContext:(id)contextToLog { if (errorCode == CHIP_NO_ERROR) { return nil; } - ChipLogError(Controller, "Creating NSError from %" CHIP_ERROR_FORMAT, errorCode.Format()); + ChipLogError(Controller, "Creating NSError from %" CHIP_ERROR_FORMAT " (context: %@)", errorCode.Format(), contextToLog); if (errorCode.IsIMStatus()) { chip::app::StatusIB status(errorCode); diff --git a/src/darwin/Framework/CHIP/MTRError_Internal.h b/src/darwin/Framework/CHIP/MTRError_Internal.h index 9997118ae95191..24916082835a6e 100644 --- a/src/darwin/Framework/CHIP/MTRError_Internal.h +++ b/src/darwin/Framework/CHIP/MTRError_Internal.h @@ -27,6 +27,7 @@ NS_ASSUME_NONNULL_BEGIN @interface MTRError : NSObject + (NSError * _Nullable)errorForCHIPErrorCode:(CHIP_ERROR)errorCode; ++ (NSError * _Nullable)errorForCHIPErrorCode:(CHIP_ERROR)errorCode logContext:(id _Nullable)contextToLog; + (NSError * _Nullable)errorForIMStatus:(const chip::app::StatusIB &)status; + (NSError * _Nullable)errorForIMStatusCode:(chip::Protocols::InteractionModel::Status)status; + (CHIP_ERROR)errorToCHIPErrorCode:(NSError * _Nullable)error; diff --git a/src/darwin/Framework/CHIP/MTRSetupPayload.mm b/src/darwin/Framework/CHIP/MTRSetupPayload.mm index d7b08c7c0a44a4..42bd7babdf3bc8 100644 --- a/src/darwin/Framework/CHIP/MTRSetupPayload.mm +++ b/src/darwin/Framework/CHIP/MTRSetupPayload.mm @@ -235,7 +235,7 @@ + (MTRSetupPayload * _Nullable)setupPayloadWithOnboardingPayload:(NSString *)onb if (!validPayload) { if (error) { - *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INVALID_ARGUMENT]; + *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INVALID_ARGUMENT logContext:onboardingPayload]; } return nil; } @@ -336,7 +336,7 @@ - (NSString * _Nullable)qrCodeString:(NSError * __autoreleasing *)error if (self.commissioningFlow == MTRCommissioningFlowInvalid) { // No idea how to map this to the standard codes. if (error != nil) { - *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INCORRECT_STATE]; + *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INCORRECT_STATE logContext:@"invalid flow"]; } return nil; } @@ -344,7 +344,7 @@ - (NSString * _Nullable)qrCodeString:(NSError * __autoreleasing *)error if (self.hasShortDiscriminator) { // Can't create a QR code with a short discriminator. if (error != nil) { - *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INCORRECT_STATE]; + *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INCORRECT_STATE logContext:@"cannot create a QR code with a short descrimintor"]; } return nil; } @@ -352,7 +352,7 @@ - (NSString * _Nullable)qrCodeString:(NSError * __autoreleasing *)error if (self.discoveryCapabilities == MTRDiscoveryCapabilitiesUnknown) { // Can't create a QR code if we don't know the discovery capabilities. if (error != nil) { - *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INCORRECT_STATE]; + *error = [MTRError errorForCHIPErrorCode:CHIP_ERROR_INCORRECT_STATE logContext:@"cannot create a QR code with unknown discovery capabilities"]; } return nil; } diff --git a/src/darwin/Framework/Matter.xcodeproj/project.pbxproj b/src/darwin/Framework/Matter.xcodeproj/project.pbxproj index 22c071844795d5..5e227bc7a8d2b2 100644 --- a/src/darwin/Framework/Matter.xcodeproj/project.pbxproj +++ b/src/darwin/Framework/Matter.xcodeproj/project.pbxproj @@ -1648,7 +1648,7 @@ isa = PBXProject; attributes = { BuildIndependentTargetsInParallel = YES; - LastUpgradeCheck = 1140; + LastUpgradeCheck = 1500; ORGANIZATIONNAME = CHIP; TargetAttributes = { 037C3CA42991A44B00B7EEE2 = { diff --git a/src/darwin/Framework/Matter.xcodeproj/xcshareddata/xcschemes/Matter Framework Tests.xcscheme b/src/darwin/Framework/Matter.xcodeproj/xcshareddata/xcschemes/Matter Framework Tests.xcscheme index a55dee131a9593..e7243c557d1fa4 100644 --- a/src/darwin/Framework/Matter.xcodeproj/xcshareddata/xcschemes/Matter Framework Tests.xcscheme +++ b/src/darwin/Framework/Matter.xcodeproj/xcshareddata/xcschemes/Matter Framework Tests.xcscheme @@ -1,6 +1,6 @@ - - diff --git a/src/darwin/Framework/Matter.xcodeproj/xcshareddata/xcschemes/Matter Framework.xcscheme b/src/darwin/Framework/Matter.xcodeproj/xcshareddata/xcschemes/Matter Framework.xcscheme index 83717233f5a54a..c93293386d9c50 100644 --- a/src/darwin/Framework/Matter.xcodeproj/xcshareddata/xcschemes/Matter Framework.xcscheme +++ b/src/darwin/Framework/Matter.xcodeproj/xcshareddata/xcschemes/Matter Framework.xcscheme @@ -1,6 +1,6 @@