From 376a2d58d16aef0dd728f36383ab3532f31e3345 Mon Sep 17 00:00:00 2001 From: Boris Zbarsky Date: Wed, 10 Apr 2024 23:14:16 -0400 Subject: [PATCH] Improve MTRDevice work item logging. Stop including the node ID in the description passed to enqueueWorkItem, because the work queue includes that already. Use hex for node IDs, cluster IDs, command/attribute IDs (but keep using decimal for endpoint IDs), to be consistent with other logging. --- src/darwin/Framework/CHIP/MTRDevice.mm | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-) diff --git a/src/darwin/Framework/CHIP/MTRDevice.mm b/src/darwin/Framework/CHIP/MTRDevice.mm index 17916610a27688..04e9ccd37a3877 100644 --- a/src/darwin/Framework/CHIP/MTRDevice.mm +++ b/src/darwin/Framework/CHIP/MTRDevice.mm @@ -1509,14 +1509,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, nodeID, endpointID, clusterID, attributeID); + MTR_LOG_INFO("Batching read attribute work item [%llu]: cannot add more work, item is full [0x%016llX:%@:0x%llx:0x%llx]", workItemID, nodeID.unsignedLongLongValue, endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue); 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, nodeID, endpointID, clusterID, attributeID); + MTR_LOG_INFO("Batching read attribute work item [%llu]: cannot add more work, parameter mismatch [0x%016llX:%@:0x%llx:0x%llx]", workItemID, nodeID.unsignedLongLongValue, endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue); return outcome; } @@ -1524,8 +1524,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, nodeID, endpointID, clusterID, attributeID); + MTR_LOG_INFO("Batching read attribute work item [%llu]: added %@ (now %tu requests total) [0x%016llX:%@:0x%llx:0x%llx]", + workItemID, readItem, readRequestsCurrent.count, nodeID.unsignedLongLongValue, endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue); outcome = MTRBatchedPartially; } NSCAssert(readRequestsNext.count == 0, @"should have batched everything or returned early"); @@ -1535,7 +1535,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, nodeID, endpointID, clusterID, attributeID); + MTR_LOG_DEFAULT("Read attribute work item [%llu] report duplicate %@ [0x%016llX:%@:0x%llx:0x%llx]", workItemID, readItem, nodeID.unsignedLongLongValue, endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue); *isDuplicate = YES; *stop = YES; return; @@ -1572,23 +1572,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, nodeID, endpointID, clusterID, attributeID); + MTR_LOG_INFO("Read attribute work item [%llu] result: %@ [0x%016llX:%@:0x%llX:0x%llX]", workItemID, values, nodeID.unsignedLongLongValue, endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue); [self _handleAttributeReport:values]; } // TODO: better retry logic if (error && (retryCount < 2)) { - MTR_LOG_ERROR("Read attribute work item [%llu] failed (will retry): %@ [%@:%@:%@:%@]", workItemID, error, nodeID, endpointID, clusterID, attributeID); + MTR_LOG_ERROR("Read attribute work item [%llu] failed (will retry): %@ [0x%016llX:%@:0x%llx:0x%llx]", workItemID, error, nodeID.unsignedLongLongValue, endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue); completion(MTRAsyncWorkNeedsRetry); } else { if (error) { - MTR_LOG_DEFAULT("Read attribute work item [%llu] failed (giving up): %@ [%@:%@:%@:%@]", workItemID, error, nodeID, endpointID, clusterID, attributeID); + MTR_LOG_DEFAULT("Read attribute work item [%llu] failed (giving up): %@ [0x%016llX:%@:0x%llx:0x%llx]", workItemID, error, nodeID.unsignedLongLongValue, endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue); } completion(MTRAsyncWorkComplete); } }]; }]; - [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"read %@ %@ %@ %@", self.nodeID, endpointID, clusterID, attributeID]; + [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"read %@ 0x%llx 0x%llx", endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue]; } return attributeValueToReturn; @@ -1656,7 +1656,7 @@ - (void)writeAttributeWithEndpointID:(NSNumber *)endpointID completion(MTRAsyncWorkComplete); }]; }]; - [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"write %@ %@ %@ %@", self.nodeID, endpointID, clusterID, attributeID]; + [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"write %@ 0x%llx 0x%llx", endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue]; } - (void)invokeCommandWithEndpointID:(NSNumber *)endpointID @@ -1806,7 +1806,7 @@ - (void)_invokeCommandWithEndpointID:(NSNumber *)endpointID workDone(values, error); }]; }]; - [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"invoke %@ %@ %@", endpointID, clusterID, commandID]; + [_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"invoke %@ 0x%llx 0x%llx", endpointID, clusterID.unsignedLongLongValue, commandID.unsignedLongLongValue]; } - (void)_invokeKnownCommandWithEndpointID:(NSNumber *)endpointID