Add metrics for OTA transfers (project-chip#39991)

Co-authored-by: Boris Zbarsky <bzbarsky@apple.com>

Author: peterv-apple

examples/darwin-framework-tool/commands/provider/OTAProviderDelegate.mm

@@ -157,6 +157,7 @@ - (void)handleBDXTransferSessionBeginForNodeID:(NSNumber * _Nonnull)nodeID
 
 - (void)handleBDXTransferSessionEndForNodeID:(NSNumber * _Nonnull)nodeID
                                   controller:(MTRDeviceController * _Nonnull)controller
+                                     metrics:(MTRMetrics * _Nonnull)metrics
                                        error:(NSError * _Nullable)error
 {
     NSLog(@"BDX TransferSession end with error: %@", error);

src/darwin/Framework/CHIP/MTRDeviceControllerDelegateBridge.mm

@@ -160,7 +160,7 @@
     if (strongDelegate && mQueue && strongController) {
 
         // Always collect the metrics to avoid unbounded growth of the stats in the collector
-        MTRMetrics * metrics = [[MTRMetricsCollector sharedInstance] metricSnapshot:TRUE];
+        MTRMetrics * metrics = [[MTRMetricsCollector sharedInstance] metricSnapshotForCommissioning:YES];
         MTR_LOG("%@ Device commissioning complete with metrics %@", strongController, metrics);
 
         if ([strongDelegate respondsToSelector:@selector(controller:commissioningComplete:nodeID:)] ||

src/darwin/Framework/CHIP/MTRMetricKeys.h

@@ -22,6 +22,17 @@ namespace chip {
 namespace Tracing {
 namespace DarwinFramework {
 
+// When metrics were originally added, they were used for logging events during the commissioning of devices. The data was sent at
+// the end of commissioning (in OnCommissioningComplete). This means that if we want to add metrics that are not related to
+// commissioning, that need to be sent outside of the commissioning of the device, we need a way to separate out metrics by a
+// category. The CHIP metrics infrastructure is fairly simple, with just a key and a numeric value. To add categories without
+// changing existing keys we've opted to use a special prefix with double underscores (dwnfw__CATEGORY__) for the keys that are in a
+// category. Any keys that do not contain this special prefix are now assumed to be used for commissioning events.
+
+// Note that these are not used for commissioning metrics, because those predate the encoding of a category.
+#define METRICS_KEY_PREFIX "dwnfw__"
+#define METRICS_KEY(category, key) METRICS_KEY_PREFIX #category "__" #key
+
 // Tracks overall commissioning via one of the setup APIs
 constexpr Tracing::MetricKey kMetricDeviceCommissioning = "dwnfw_device_commissioning";
 
@@ -94,6 +105,23 @@ constexpr Tracing::MetricKey kMetricUnexpectedCQualityUpdate = "dwnpm_bad_c_attr
 // Setup from darwin MTRDevice for initial subscription to a device
 constexpr Tracing::MetricKey kMetricMTRDeviceInitialSubscriptionSetup = "dwnpm_dev_initial_subscription_setup";
 
+constexpr Tracing::MetricKey kMetricOTATransfer = METRICS_KEY(ota, transfer);
+
+// Device Vendor ID
+constexpr Tracing::MetricKey kMetricOTADeviceVendorID = METRICS_KEY(ota, device_vendor_id);
+
+// Device Product ID
+constexpr Tracing::MetricKey kMetricOTADeviceProductID = METRICS_KEY(ota, device_product_id);
+
+// Device Uses Thread
+constexpr Tracing::MetricKey kMetricOTADeviceUsesThread = METRICS_KEY(ota, device_uses_thread_bool);
+
+constexpr Tracing::MetricKey kMetricOTATransferLength = METRICS_KEY(ota, transfer_length);
+
+constexpr Tracing::MetricKey kMetricOTATransferOffset = METRICS_KEY(ota, transfer_offset);
+
+constexpr Tracing::MetricKey kMetricOTATNumBytesProcessed = METRICS_KEY(ota, num_bytes_processed);
+
 } // namespace DarwinFramework
 } // namespace Tracing
 } // namespace chip

src/darwin/Framework/CHIP/MTRMetricsCollector.h

@@ -44,15 +44,26 @@ void ShutdownMetricsCollection();
 + (instancetype)sharedInstance;
 
 /**
- * @brief This method creates a snapshot of the metrics collected until the current point in time
- * and returns an object with the stats.
+ * @brief This method creates a snapshot of the metrics for commissioning collected until the current
+ *        point in time and returns an object with the stats.
  *
  * @param [in] resetCollection Boolean that specifies whether or not to clear the stats collected after
  *                             creating the snapshot.
  *
  * @return MTRMetric object representing the metric data.
  */
-- (MTRMetrics *)metricSnapshot:(BOOL)resetCollection;
+- (MTRMetrics *)metricSnapshotForCommissioning:(BOOL)resetCollection;
+
+/**
+ * @brief This method creates a snapshot of the metrics for a category (other than for commissioning)
+ *        that were collected until the current point in time and returns an object with those stats.
+ *
+ * @param [in] removeMetrics Boolean that specifies whether to clear the stats for the category after
+ *                           creating the snapshot.
+ *
+ * @return MTRMetric object representing the metric data.
+ */
+- (MTRMetrics *)metricSnapshotForCategory:(NSString *)category removeMetrics:(BOOL)removeMetrics;
 
 /**
  * @brief This method clears any metrics collected.

src/darwin/Framework/CHIP/MTRMetricsCollector.mm

@@ -17,6 +17,7 @@
 
 #import "MTRMetricsCollector.h"
 #import "MTRLogging_Internal.h"
+#import "MTRMetricKeys.h"
 #import "MTRMetrics.h"
 #import "MTRMetrics_Internal.h"
 #import <MTRUnfairLock.h>
@@ -251,18 +252,45 @@ - (void)handleMetricEvent:(MetricEvent)event
     }
 }
 
-- (MTRMetrics *)metricSnapshot:(BOOL)resetCollection
+- (MTRMetrics *)metricSnapshotForCommissioning:(BOOL)resetCollection
 {
     std::lock_guard lock(_lock);
 
+    NSMutableArray * keysToDelete = [NSMutableArray array];
     MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:[_metricsDataCollection count]];
-    for (NSString * key in _metricsDataCollection) {
-        [metrics setMetricData:_metricsDataCollection[key] forKey:key];
-    }
+    [_metricsDataCollection enumerateKeysAndObjectsUsingBlock:^(NSString * key, MTRMetricData * obj, BOOL * stop) {
+        // Commissioning metric keys predate the encoding of a category, so we need to filter out
+        // all keys that use the encoding scheme here.
+        if (![key hasPrefix:@METRICS_KEY_PREFIX]) {
+            [keysToDelete addObject:key];
+            [metrics setMetricData:obj forKey:key];
+        }
+    }];
 
     // Clear curent stats, if specified
     if (resetCollection) {
-        [_metricsDataCollection removeAllObjects];
+        [_metricsDataCollection removeObjectsForKeys:keysToDelete];
+    }
+    return metrics;
+}
+
+- (MTRMetrics *)metricSnapshotForCategory:(NSString *)category removeMetrics:(BOOL)removeMetrics
+{
+    std::lock_guard lock(_lock);
+
+    NSString * keyPrefix = [NSString stringWithFormat:@METRICS_KEY_PREFIX "%@__", category];
+    NSMutableArray * keysToDelete = [NSMutableArray array];
+    MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:[_metricsDataCollection count]];
+    [_metricsDataCollection enumerateKeysAndObjectsUsingBlock:^(NSString * key, MTRMetricData * obj, BOOL * stop) {
+        if ([key hasPrefix:keyPrefix]) {
+            [keysToDelete addObject:key];
+            [metrics setMetricData:obj forKey:key];
+        }
+    }];
+
+    // Clear curent stats, if specified
+    if (removeMetrics) {
+        [_metricsDataCollection removeObjectsForKeys:keysToDelete];
     }
     return metrics;
 }

src/darwin/Framework/CHIP/MTROTAImageTransferHandler.h

@@ -78,6 +78,8 @@ class MTROTAImageTransferHandler : public chip::bdx::AsyncResponder {
     bool mIsPeerNodeAKnownThreadDevice = NO;
 
     chip::System::Clock::Milliseconds32 mBDXThrottleIntervalForThreadDevices;
+
+    size_t mNumBytesProcessed = 0;
 };
 
 NS_ASSUME_NONNULL_END

src/darwin/Framework/CHIP/MTROTAImageTransferHandler.mm

@@ -19,6 +19,8 @@
 #import "MTRDeviceControllerFactory_Internal.h"
 #import "MTRDeviceController_Internal.h"
 #import "MTRError_Internal.h"
+#import "MTRMetricKeys.h"
+#import "MTRMetricsCollector.h"
 #import "MTROTAUnsolicitedBDXMessageHandler.h"
 #import "NSStringSpanConversion.h"
 
@@ -28,6 +30,7 @@
 using namespace chip;
 using namespace chip::bdx;
 using namespace chip::app;
+using namespace chip::Tracing::DarwinFramework;
 
 constexpr uint16_t kMaxBdxBlockSize = 1024;
 
@@ -199,6 +202,11 @@ - (void)SetOtaImageTransferHandler:(MTROTAImageTransferHandler *)otaImageTransfe
     auto * controller = [[MTRDeviceControllerFactory sharedInstance] runningControllerForFabricIndex:mPeer.GetFabricIndex()];
     VerifyOrReturnError(controller != nil, CHIP_ERROR_INCORRECT_STATE);
 
+    mNumBytesProcessed = 0;
+
+    MATTER_LOG_METRIC_BEGIN(kMetricOTATransfer);
+    MATTER_LOG_METRIC(kMetricOTATransferOffset, uint32_t(mTransfer.GetStartOffset()));
+
     MTROTAImageTransferHandlerWrapper * __weak weakWrapper = mOTAImageTransferHandlerWrapper;
 
     auto completionHandler = ^(NSError * _Nullable error) {
@@ -284,8 +292,24 @@ - (void)SetOtaImageTransferHandler:(MTROTAImageTransferHandler *)otaImageTransfe
         return;
     }
 
+    auto * device = [MTRDevice deviceWithNodeID:nodeId controller:controller];
+
+    MATTER_LOG_METRIC(kMetricOTADeviceVendorID, device.vendorID.unsignedIntValue);
+    MATTER_LOG_METRIC(kMetricOTADeviceProductID, device.productID.unsignedIntValue);
+    MATTER_LOG_METRIC(kMetricOTADeviceUsesThread, mIsPeerNodeAKnownThreadDevice);
+    MATTER_LOG_METRIC(kMetricOTATNumBytesProcessed, uint32_t(mNumBytesProcessed));
+    MATTER_LOG_METRIC_END(kMetricOTATransfer, error);
+
+    // Always collect the metrics to avoid unbounded growth of the stats in the collector
+    MTRMetrics * metrics = [[MTRMetricsCollector sharedInstance] metricSnapshotForCategory:@("ota") removeMetrics:YES];
     auto nsError = [MTRError errorForCHIPErrorCode:error];
-    if ([strongDelegate respondsToSelector:@selector(handleBDXTransferSessionEndForNodeID:controller:error:)]) {
+    if ([strongDelegate respondsToSelector:@selector(handleBDXTransferSessionEndForNodeID:controller:metrics:error:)]) {
+        dispatch_async(delegateQueue, ^{
+            [strongDelegate handleBDXTransferSessionEndForNodeID:nodeId controller:controller
+                                                         metrics:metrics
+                                                           error:nsError];
+        });
+    } else if ([strongDelegate respondsToSelector:@selector(handleBDXTransferSessionEndForNodeID:controller:error:)]) {
         dispatch_async(delegateQueue, ^{
             [strongDelegate handleBDXTransferSessionEndForNodeID:nodeId
                                                       controller:controller
@@ -330,6 +354,9 @@ - (void)SetOtaImageTransferHandler:(MTROTAImageTransferHandler *)otaImageTransfe
     MTROTAImageTransferHandlerWrapper * __weak weakWrapper = mOTAImageTransferHandlerWrapper;
 
     auto respondWithBlock = ^(NSData * _Nullable data, BOOL isEOF) {
+        if (data) {
+            mNumBytesProcessed += data.length;
+        }
         [controller
             asyncDispatchToMatterQueue:^() {
                 assertChipStackLockedByCurrentThread();

src/darwin/Framework/CHIP/MTROTAProviderDelegate.h

@@ -21,6 +21,7 @@
 #import <Matter/MTRDefines.h>
 
 @class MTRDeviceController;
+@class MTRMetrics;
 
 NS_ASSUME_NONNULL_BEGIN
 
@@ -140,7 +141,15 @@ NS_ASSUME_NONNULL_BEGIN
  */
 - (void)handleBDXTransferSessionEndForNodeID:(NSNumber *)nodeID
                                   controller:(MTRDeviceController *)controller
-                                       error:(NSError * _Nullable)error;
+                                     metrics:(MTRMetrics *)metrics
+                                       error:(NSError * _Nullable)error
+    MTR_AVAILABLE(ios(26.1), macos(26.1), watchos(26.1), tvos(26.1));
+
+- (void)handleBDXTransferSessionEndForNodeID:(NSNumber *)nodeID
+                                  controller:(MTRDeviceController *)controller
+                                       error:(NSError * _Nullable)error
+    MTR_DEPRECATED_WITH_REPLACEMENT("handleBDXTransferSessionEndForNodeID:controller:metrics:error:", ios(16.1, 26.1),
+        macos(13.0, 26.1), watchos(9.1, 26.1), tvos(16.1, 26.1));
 
 /**
  * Notify the delegate when a BDX Query message has been received for some node.