Skip to content

Commit

Permalink
Improve MTRDevice work item logging.
Browse files Browse the repository at this point in the history 
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.
  • Loading branch information
@bzbarsky-apple
bzbarsky-apple committed Apr 11, 2024
1 parent 774f6c4 commit 376a2d5
Showing 1 changed file with 11 additions and 11 deletions.
22 changes: 11 additions & 11 deletions src/darwin/Framework/CHIP/MTRDevice.mm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1509,23 +1509,23 @@ 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;
}

// merge the next item's first request into the current item's list
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");
Expand All @@ -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;
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand Down

0 comments on commit 376a2d5

Please sign in to comment.