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.

Sign up for GitHub

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

Improve MTRDevice work item logging. #32936

Merged
merged 1 commit into from
Apr 11, 2024
Merged

Improve MTRDevice work item logging. #32936

Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
22 changes: 11 additions & 11 deletions src/darwin/Framework/CHIP/MTRDevice.mm
View file
Open in desktop
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
Loading