Improve some MTRDeviceController logging. (#35609)

More things should include context about which controller is involved.
project-chip · Sep 17, 2024 · add0bf1 · add0bf1
1 parent 010ad94
commit add0bf1
Show file tree

Hide file tree

Showing 4 changed files with 19 additions and 15 deletions.
diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerDelegateBridge.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerDelegateBridge.mm
@@ -62,7 +62,9 @@
 
 void MTRDeviceControllerDelegateBridge::OnStatusUpdate(chip::Controller::DevicePairingDelegate::Status status)
 {
-    MTR_LOG("DeviceControllerDelegate status updated: %d", status);
+    MTRDeviceController * strongController = mController;
+
+    MTR_LOG("%@ DeviceControllerDelegate status updated: %d", strongController, status);
 
     // If pairing failed, PASE failed. However, since OnPairingComplete(failure_code) might not be invoked in all cases, mark
     // end of PASE with timeout as assumed failure. If OnPairingComplete is invoked, the right error code will be updated in
@@ -72,7 +74,6 @@
     }
 
     id<MTRDeviceControllerDelegate> strongDelegate = mDelegate;
-    MTRDeviceController * strongController = mController;
     if (strongDelegate && mQueue && strongController) {
         if ([strongDelegate respondsToSelector:@selector(controller:statusUpdate:)]) {
             MTRCommissioningStatus commissioningStatus = MapStatus(status);
@@ -93,15 +94,16 @@
 
 void MTRDeviceControllerDelegateBridge::OnPairingComplete(CHIP_ERROR error)
 {
+    MTRDeviceController * strongController = mController;
+
     if (error == CHIP_NO_ERROR) {
-        MTR_LOG("MTRDeviceControllerDelegate PASE session establishment succeeded.");
+        MTR_LOG("%@ MTRDeviceControllerDelegate PASE session establishment succeeded.", strongController);
     } else {
-        MTR_LOG_ERROR("MTRDeviceControllerDelegate PASE session establishment failed: %" CHIP_ERROR_FORMAT, error.Format());
+        MTR_LOG_ERROR("%@ MTRDeviceControllerDelegate PASE session establishment failed: %" CHIP_ERROR_FORMAT, strongController, error.Format());
     }
     MATTER_LOG_METRIC_END(kMetricSetupPASESession, error);
 
     id<MTRDeviceControllerDelegate> strongDelegate = mDelegate;
-    MTRDeviceController * strongController = mController;
     if (strongDelegate && mQueue && strongController) {
         if ([strongDelegate respondsToSelector:@selector(controller:commissioningSessionEstablishmentDone:)]) {
             dispatch_async(mQueue, ^{
@@ -121,13 +123,14 @@
 
 void MTRDeviceControllerDelegateBridge::OnReadCommissioningInfo(const chip::Controller::ReadCommissioningInfo & info)
 {
+    MTRDeviceController * strongController = mController;
+
     chip::VendorId vendorId = info.basic.vendorId;
     uint16_t productId = info.basic.productId;
 
-    MTR_LOG("DeviceControllerDelegate Read Commissioning Info. VendorId %u ProductId %u", vendorId, productId);
+    MTR_LOG("%@ DeviceControllerDelegate Read Commissioning Info. VendorId %u ProductId %u", strongController, vendorId, productId);
 
     id<MTRDeviceControllerDelegate> strongDelegate = mDelegate;
-    MTRDeviceController * strongController = mController;
     if (strongDelegate && mQueue && strongController) {
         if ([strongDelegate respondsToSelector:@selector(controller:readCommissioningInfo:)]) {
             dispatch_async(mQueue, ^{
@@ -140,16 +143,17 @@
 
 void MTRDeviceControllerDelegateBridge::OnCommissioningComplete(chip::NodeId nodeId, CHIP_ERROR error)
 {
-    MTR_LOG("DeviceControllerDelegate Commissioning complete. NodeId %llu Status %s", nodeId, chip::ErrorStr(error));
+    MTRDeviceController * strongController = mController;
+
+    MTR_LOG("%@ DeviceControllerDelegate Commissioning complete. NodeId 0x%016llx Status %s", strongController, nodeId, chip::ErrorStr(error));
     MATTER_LOG_METRIC_END(kMetricDeviceCommissioning, error);
 
     id<MTRDeviceControllerDelegate> strongDelegate = mDelegate;
-    MTRDeviceController * strongController = mController;
     if (strongDelegate && mQueue && strongController) {
 
         // Always collect the metrics to avoid unbounded growth of the stats in the collector
         MTRMetrics * metrics = [[MTRMetricsCollector sharedInstance] metricSnapshot:TRUE];
-        MTR_LOG("Device commissioning complete with metrics %@", metrics);
+        MTR_LOG("%@ Device commissioning complete with metrics %@", strongController, metrics);
 
         if ([strongDelegate respondsToSelector:@selector(controller:commissioningComplete:nodeID:)] ||
             [strongDelegate respondsToSelector:@selector(controller:commissioningComplete:nodeID:metrics:)]) {

diff --git a/src/darwin/Framework/CHIP/MTRDeviceController_Concrete.mm b/src/darwin/Framework/CHIP/MTRDeviceController_Concrete.mm
@@ -832,7 +832,7 @@ - (BOOL)setupCommissioningSessionWithPayload:(MTRSetupPayload *)payload
         return NO;
     }
 
-    MTR_LOG("Setting up commissioning session for device ID 0x%016llX with setup payload %@", newNodeID.unsignedLongLongValue, payload);
+    MTR_LOG("%@ Setting up commissioning session for device ID 0x%016llX with setup payload %@", self, newNodeID.unsignedLongLongValue, payload);
 
     [[MTRMetricsCollector sharedInstance] resetMetrics];
 

diff --git a/src/darwin/Framework/CHIP/ServerEndpoint/MTRServerCluster.mm b/src/darwin/Framework/CHIP/ServerEndpoint/MTRServerCluster.mm
@@ -346,8 +346,8 @@ - (BOOL)associateWithController:(nullable MTRDeviceController *)controller
 
     _deviceController = controller;
 
-    MTR_LOG("Associated %@, attribute count %llu, with controller", [self _descriptionWhileLocked],
-        static_cast<unsigned long long>(attributeCount));
+    MTR_LOG("Associated %@, attribute count %llu, with controller %@", [self _descriptionWhileLocked],
+        static_cast<unsigned long long>(attributeCount), controller);
 
     return YES;
 }

diff --git a/src/darwin/Framework/CHIP/ServerEndpoint/MTRServerEndpoint.mm b/src/darwin/Framework/CHIP/ServerEndpoint/MTRServerEndpoint.mm
@@ -311,8 +311,8 @@ - (BOOL)finishAssociationWithController:(nullable MTRDeviceController *)controll
 
     _deviceController = controller;
 
-    MTR_LOG("Associated %@, cluster count %llu, with controller",
-        self, static_cast<unsigned long long>(clusterCount));
+    MTR_LOG("Associated %@, cluster count %llu, with controller %@",
+        self, static_cast<unsigned long long>(clusterCount), controller);
 
     return YES;
 }