Skip to content

Commit 84ee115

Browse files
bzbarsky-applebzbarsky-apple
authored
Log the outgoing write values and command payloads in MTRDevice/MTRBaseDevice. (project-chip#35699)
1 parent 4842bfc commit 84ee115

5 files changed

+79
-30
lines changed

‎src/darwin/Framework/CHIP/MTRBaseDevice.mm

+31
Original file line numberDiff line numberDiff line change
@@ -1000,6 +1000,8 @@ - (void)readAttributePaths:(NSArray<MTRAttributeRequestPath *> * _Nullable)attri
10001000
queue:(dispatch_queue_t)queue
10011001
completion:(MTRDeviceResponseHandler)completion
10021002
{
1003+
MTR_LOG("%@ readAttributePaths: %@, eventPaths: %@", self, attributePaths, eventPaths);
1004+
10031005
[self readAttributePaths:attributePaths eventPaths:eventPaths params:params includeDataVersion:NO queue:queue completion:completion];
10041006
}
10051007

@@ -1010,6 +1012,9 @@ - (void)readAttributePaths:(NSArray<MTRAttributeRequestPath *> * _Nullable)attri
10101012
queue:(dispatch_queue_t)queue
10111013
completion:(MTRDeviceResponseHandler)completion
10121014
{
1015+
// NOTE: Do not log the read here. This is called ether from
1016+
// readAttributePaths:eventPaths:params:queue:completion: or MTRDevice, both
1017+
// of which already log, and we want to be able to tell the two codepaths apart.
10131018
if ((attributePaths == nil || [attributePaths count] == 0) && (eventPaths == nil || [eventPaths count] == 0)) {
10141019
// No paths, just return an empty array.
10151020
dispatch_async(queue, ^{
@@ -1166,6 +1171,19 @@ - (void)writeAttributeWithEndpointID:(NSNumber *)endpointID
11661171
timedWriteTimeout:(NSNumber * _Nullable)timeoutMs
11671172
queue:(dispatch_queue_t)queue
11681173
completion:(MTRDeviceResponseHandler)completion
1174+
{
1175+
MTR_LOG("%@ write %@ 0x%llx 0x%llx: %@", self, endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue, value);
1176+
1177+
[self _writeAttributeWithEndpointID:endpointID clusterID:clusterID attributeID:attributeID value:value timedWriteTimeout:timeoutMs queue:queue completion:completion];
1178+
}
1179+
1180+
- (void)_writeAttributeWithEndpointID:(NSNumber *)endpointID
1181+
clusterID:(NSNumber *)clusterID
1182+
attributeID:(NSNumber *)attributeID
1183+
value:(id)value
1184+
timedWriteTimeout:(NSNumber * _Nullable)timeoutMs
1185+
queue:(dispatch_queue_t)queue
1186+
completion:(MTRDeviceResponseHandler)completion
11691187
{
11701188
auto * bridge = new MTRDataValueDictionaryCallbackBridge(queue, completion,
11711189
^(ExchangeManager & exchangeManager, const SessionHandle & session, MTRDataValueDictionaryCallback successCb,
@@ -1346,6 +1364,7 @@ - (void)invokeCommandWithEndpointID:(NSNumber *)endpointID
13461364
commandFields:commandFields
13471365
timedInvokeTimeout:timeoutMs
13481366
serverSideProcessingTimeout:nil
1367+
logCall:YES
13491368
queue:queue
13501369
completion:completion];
13511370
}
@@ -1356,6 +1375,7 @@ - (void)_invokeCommandWithEndpointID:(NSNumber *)endpointID
13561375
commandFields:(id)commandFields
13571376
timedInvokeTimeout:(NSNumber * _Nullable)timeoutMs
13581377
serverSideProcessingTimeout:(NSNumber * _Nullable)serverSideProcessingTimeout
1378+
logCall:(BOOL)logCall
13591379
queue:(dispatch_queue_t)queue
13601380
completion:(MTRDeviceResponseHandler)completion
13611381
{
@@ -1376,6 +1396,10 @@ - (void)_invokeCommandWithEndpointID:(NSNumber *)endpointID
13761396
timeoutMs = MTRClampedNumber(timeoutMs, @(1), @(UINT16_MAX));
13771397
}
13781398

1399+
if (logCall) {
1400+
MTR_LOG("%@ invoke %@ 0x%llx 0x%llx: %@", self, endpointID, clusterID.unsignedLongLongValue, commandID.unsignedLongLongValue, commandFields);
1401+
}
1402+
13791403
auto * bridge = new MTRDataValueDictionaryCallbackBridge(queue, completion,
13801404
^(ExchangeManager & exchangeManager, const SessionHandle & session, MTRDataValueDictionaryCallback successCb,
13811405
MTRErrorCallback failureCb, MTRCallbackBridgeBase * bridge) {
@@ -1499,6 +1523,7 @@ - (void)_invokeKnownCommandWithEndpointID:(NSNumber *)endpointID
14991523
commandFields:commandFields
15001524
timedInvokeTimeout:timeout
15011525
serverSideProcessingTimeout:serverSideProcessingTimeout
1526+
logCall:YES
15021527
queue:queue
15031528
completion:responseHandler];
15041529
}
@@ -2157,6 +2182,12 @@ - (void)downloadLogOfType:(MTRDiagnosticLogType)type
21572182
completion:completion];
21582183
}
21592184

2185+
- (NSString *)description
2186+
{
2187+
return [NSString
2188+
stringWithFormat:@"<%@: %p, node: %016llX-%016llX (%llu)>", NSStringFromClass(self.class), self, _deviceController.compressedFabricID.unsignedLongLongValue, _nodeID, _nodeID];
2189+
}
2190+
21602191
@end
21612192

21622193
@implementation MTRBaseDevice (Deprecated)

‎src/darwin/Framework/CHIP/MTRBaseDevice_Internal.h

+14-1
Original file line numberDiff line numberDiff line change
@@ -116,14 +116,16 @@ static inline MTRTransportType MTRMakeTransportType(chip::Transport::Type type)
116116

117117
/**
118118
* Like the public invokeCommandWithEndpointID but allows passing through a
119-
* serverSideProcessingTimeout.
119+
* serverSideProcessingTimeout and controlling whether we log the call (so we
120+
* can not log when the call is not actually originating with MTRBaseDevice).
120121
*/
121122
- (void)_invokeCommandWithEndpointID:(NSNumber *)endpointID
122123
clusterID:(NSNumber *)clusterID
123124
commandID:(NSNumber *)commandID
124125
commandFields:(id)commandFields
125126
timedInvokeTimeout:(NSNumber * _Nullable)timeoutMs
126127
serverSideProcessingTimeout:(NSNumber * _Nullable)serverSideProcessingTimeout
128+
logCall:(BOOL)logCall
127129
queue:(dispatch_queue_t)queue
128130
completion:(MTRDeviceResponseHandler)completion;
129131

@@ -195,6 +197,17 @@ static inline MTRTransportType MTRMakeTransportType(chip::Transport::Type type)
195197
queue:(dispatch_queue_t)queue
196198
completion:(MTRDeviceResponseHandler)completion;
197199

200+
/**
201+
* Same as the public version, except for logging. For use from MTRDevice only.
202+
*/
203+
- (void)_writeAttributeWithEndpointID:(NSNumber *)endpointID
204+
clusterID:(NSNumber *)clusterID
205+
attributeID:(NSNumber *)attributeID
206+
value:(id)value
207+
timedWriteTimeout:(NSNumber * _Nullable)timeoutMs
208+
queue:(dispatch_queue_t)queue
209+
completion:(MTRDeviceResponseHandler)completion;
210+
198211
@end
199212

200213
@interface MTRClusterPath ()

‎src/darwin/Framework/CHIP/MTRDeviceOverXPC.mm

+8-7
Original file line numberDiff line numberDiff line change
@@ -194,13 +194,13 @@ - (void)readAttributePaths:(NSArray<MTRAttributeRequestPath *> * _Nullable)attri
194194
}
195195
}
196196

197-
- (void)writeAttributeWithEndpointID:(NSNumber *)endpointID
198-
clusterID:(NSNumber *)clusterID
199-
attributeID:(NSNumber *)attributeID
200-
value:(id)value
201-
timedWriteTimeout:(NSNumber * _Nullable)timeoutMs
202-
queue:(dispatch_queue_t)queue
203-
completion:(MTRDeviceResponseHandler)completion
197+
- (void)_writeAttributeWithEndpointID:(NSNumber *)endpointID
198+
clusterID:(NSNumber *)clusterID
199+
attributeID:(NSNumber *)attributeID
200+
value:(id)value
201+
timedWriteTimeout:(NSNumber * _Nullable)timeoutMs
202+
queue:(dispatch_queue_t)queue
203+
completion:(MTRDeviceResponseHandler)completion
204204
{
205205
MTR_LOG_DEBUG("Writing attribute ...");
206206

@@ -276,6 +276,7 @@ - (void)_invokeCommandWithEndpointID:(NSNumber *)endpointID
276276
commandFields:(id)commandFields
277277
timedInvokeTimeout:(NSNumber * _Nullable)timeoutMs
278278
serverSideProcessingTimeout:(NSNumber * _Nullable)serverSideProcessingTimeout
279+
logCall:(BOOL)logCall
279280
queue:(dispatch_queue_t)queue
280281
completion:(MTRDeviceResponseHandler)completion
281282
{

‎src/darwin/Framework/CHIP/MTRDevice_Concrete.mm

+23-19
Original file line numberDiff line numberDiff line change
@@ -2862,6 +2862,8 @@ - (void)writeAttributeWithEndpointID:(NSNumber *)endpointID
28622862
expectedValueInterval:(NSNumber *)expectedValueInterval
28632863
timedWriteTimeout:(NSNumber * _Nullable)timeout
28642864
{
2865+
value = [value copy];
2866+
28652867
if (timeout) {
28662868
timeout = MTRClampedNumber(timeout, @(1), @(UINT16_MAX));
28672869
}
@@ -2901,7 +2903,7 @@ - (void)writeAttributeWithEndpointID:(NSNumber *)endpointID
29012903
// [ attribute path, value, timedWriteTimeout, expectedValueID ]
29022904
//
29032905
// where expectedValueID is stored as NSNumber and NSNull represents nil timeouts
2904-
auto * writeData = @[ attributePath, [value copy], timeout ?: [NSNull null], @(expectedValueID) ];
2906+
auto * writeData = @[ attributePath, value, timeout ?: [NSNull null], @(expectedValueID) ];
29052907

29062908
NSMutableArray<NSArray *> * writeRequests = [NSMutableArray arrayWithObject:writeData];
29072909

@@ -2958,24 +2960,24 @@ - (void)writeAttributeWithEndpointID:(NSNumber *)endpointID
29582960
}
29592961

29602962
[baseDevice
2961-
writeAttributeWithEndpointID:path.endpoint
2962-
clusterID:path.cluster
2963-
attributeID:path.attribute
2964-
value:request[MTRDeviceWriteRequestFieldValueIndex]
2965-
timedWriteTimeout:timedWriteTimeout
2966-
queue:self.queue
2967-
completion:^(NSArray<NSDictionary<NSString *, id> *> * _Nullable values, NSError * _Nullable error) {
2968-
if (error) {
2969-
MTR_LOG_ERROR("Write attribute work item [%llu] failed: %@", workItemID, error);
2970-
if (useValueAsExpectedValue) {
2971-
NSNumber * expectedValueID = request[MTRDeviceWriteRequestFieldExpectedValueIDIndex];
2972-
[self removeExpectedValueForAttributePath:attributePath expectedValueID:expectedValueID.unsignedLongLongValue];
2973-
}
2974-
}
2975-
completion(MTRAsyncWorkComplete);
2976-
}];
2963+
_writeAttributeWithEndpointID:path.endpoint
2964+
clusterID:path.cluster
2965+
attributeID:path.attribute
2966+
value:request[MTRDeviceWriteRequestFieldValueIndex]
2967+
timedWriteTimeout:timedWriteTimeout
2968+
queue:self.queue
2969+
completion:^(NSArray<NSDictionary<NSString *, id> *> * _Nullable values, NSError * _Nullable error) {
2970+
if (error) {
2971+
MTR_LOG_ERROR("Write attribute work item [%llu] failed: %@", workItemID, error);
2972+
if (useValueAsExpectedValue) {
2973+
NSNumber * expectedValueID = request[MTRDeviceWriteRequestFieldExpectedValueIDIndex];
2974+
[self removeExpectedValueForAttributePath:attributePath expectedValueID:expectedValueID.unsignedLongLongValue];
2975+
}
2976+
}
2977+
completion(MTRAsyncWorkComplete);
2978+
}];
29772979
}];
2978-
[_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"write %@ 0x%llx 0x%llx", endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue];
2980+
[_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"write %@ 0x%llx 0x%llx: %@", endpointID, clusterID.unsignedLongLongValue, attributeID.unsignedLongLongValue, value];
29792981
}
29802982

29812983
- (NSArray<NSDictionary<NSString *, id> *> *)readAttributePaths:(NSArray<MTRAttributeRequestPath *> *)attributePaths
@@ -3045,6 +3047,7 @@ - (void)_invokeCommandWithEndpointID:(NSNumber *)endpointID
30453047

30463048
serverSideProcessingTimeout = [serverSideProcessingTimeout copy];
30473049
timeout = [timeout copy];
3050+
commandFields = [commandFields copy];
30483051

30493052
if (timeout == nil && MTRCommandNeedsTimedInvoke(clusterID, commandID)) {
30503053
timeout = @(MTR_DEFAULT_TIMED_INTERACTION_TIMEOUT_MS);
@@ -3105,6 +3108,7 @@ - (void)_invokeCommandWithEndpointID:(NSNumber *)endpointID
31053108
commandFields:commandFields
31063109
timedInvokeTimeout:timedInvokeTimeout
31073110
serverSideProcessingTimeout:serverSideProcessingTimeout
3111+
logCall:NO
31083112
queue:self.queue
31093113
completion:^(NSArray<NSDictionary<NSString *, id> *> * _Nullable values, NSError * _Nullable error) {
31103114
// Log the data at the INFO level (not usually persisted permanently),
@@ -3120,7 +3124,7 @@ - (void)_invokeCommandWithEndpointID:(NSNumber *)endpointID
31203124
workDone(values, error);
31213125
}];
31223126
}];
3123-
[_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"invoke %@ 0x%llx 0x%llx", endpointID, clusterID.unsignedLongLongValue, commandID.unsignedLongLongValue];
3127+
[_asyncWorkQueue enqueueWorkItem:workItem descriptionWithFormat:@"invoke %@ 0x%llx 0x%llx: %@", endpointID, clusterID.unsignedLongLongValue, commandID.unsignedLongLongValue, commandFields];
31243128
}
31253129

31263130
- (void)openCommissioningWindowWithSetupPasscode:(NSNumber *)setupPasscode

‎src/darwin/Framework/CHIP/MTRDiagnosticLogsDownloader.mm

+3-3
Original file line numberDiff line numberDiff line change
@@ -446,15 +446,15 @@ - (void)downloadLogFromNodeWithID:(NSNumber *)nodeID
446446
[download checkInteractionModelResponse:response error:error];
447447
};
448448

449-
auto * device = [MTRBaseDevice deviceWithNodeID:nodeID controller:controller];
450-
auto * cluster = [[MTRBaseClusterDiagnosticLogs alloc] initWithDevice:device endpointID:@(kDiagnosticLogsEndPoint) queue:queue];
449+
auto * device = [MTRDevice deviceWithNodeID:nodeID controller:controller];
450+
auto * cluster = [[MTRClusterDiagnosticLogs alloc] initWithDevice:device endpointID:@(kDiagnosticLogsEndPoint) queue:queue];
451451

452452
auto * params = [[MTRDiagnosticLogsClusterRetrieveLogsRequestParams alloc] init];
453453
params.intent = @(type);
454454
params.requestedProtocol = @(MTRDiagnosticLogsTransferProtocolBDX);
455455
params.transferFileDesignator = download.fileDesignator;
456456

457-
[cluster retrieveLogsRequestWithParams:params completion:interactionModelDone];
457+
[cluster retrieveLogsRequestWithParams:params expectedValues:nil expectedValueInterval:nil completion:interactionModelDone];
458458

459459
if (timeoutInSeconds > 0) {
460460
auto err = _bridge->StartBDXTransferTimeout(download, timeoutInSeconds);

0 commit comments

Comments
 (0)