Improve MTRDevice work item logging. (#32936)
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.
diff --git a/src/darwin/Framework/CHIP/MTRDevice.mm b/src/darwin/Framework/CHIP/MTRDevice.mm
index a5ae390..31cdc3a 100644
--- a/src/darwin/Framework/CHIP/MTRDevice.mm
+++ b/src/darwin/Framework/CHIP/MTRDevice.mm
@@ -1522,14 +1522,14 @@
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;
}
@@ -1537,8 +1537,8 @@
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");
@@ -1548,7 +1548,7 @@
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;
@@ -1585,23 +1585,23 @@
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;
@@ -1669,7 +1669,7 @@
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
@@ -1819,7 +1819,7 @@
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
