diff --git a/src/app/clusters/wifi-network-diagnostics-server/wifi-network-diagnostics-server.cpp b/src/app/clusters/wifi-network-diagnostics-server/wifi-network-diagnostics-server.cpp index f116def50c089a..3cf9239ddff59e 100644 --- a/src/app/clusters/wifi-network-diagnostics-server/wifi-network-diagnostics-server.cpp +++ b/src/app/clusters/wifi-network-diagnostics-server/wifi-network-diagnostics-server.cpp @@ -28,6 +28,7 @@ #include #include #include +#include using namespace chip; using namespace chip::app; @@ -163,7 +164,7 @@ CHIP_ERROR WiFiDiagosticsAttrAccess::ReadWiFiRssi(AttributeValueEncoder & aEncod { rssi.SetNonNull(value); ChipLogProgress(Zcl, "The current RSSI of the Node’s Wi-Fi radio in dB: %d", value); - MATTER_TRACE_METRIC("wifi_rssi", value); + MATTER_LOG_METRIC(chip::Tracing::kMetricWiFiRSSI, value); } else { diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerDelegateBridge.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerDelegateBridge.mm index e1c49031e3abb2..04ac68a6dae1fe 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerDelegateBridge.mm +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerDelegateBridge.mm @@ -17,9 +17,10 @@ #import "MTRDeviceControllerDelegateBridge.h" #import "MTRDeviceController.h" +#import "MTRDeviceController_Internal.h" #import "MTRError_Internal.h" #import "MTRLogging_Internal.h" -#import "MTRMetrics_Internal.h" +#import "MTRMetricsCollector.h" MTRDeviceControllerDelegateBridge::MTRDeviceControllerDelegateBridge(void) : mDelegate(nil) @@ -130,15 +131,10 @@ nodeID = @(nodeId); } + // If the client implements the metrics delegate, prefer that over others if ([strongDelegate respondsToSelector:@selector(controller:commissioningComplete:nodeID:metrics:)]) { - MTRMetrics * metrics = [MTRMetrics new]; - - if (nsError) { - [metrics setValue:nsError forKey:MTRMetricCommissioningStatusKey]; - } else { - auto * error = [NSError errorWithDomain:MTRErrorDomain code:0 userInfo:nil]; - [metrics setValue:error forKey:MTRMetricCommissioningStatusKey]; - } + // Create a snapshot and clear for next operation + MTRMetrics * metrics = [[MTRMetricsCollector sharedInstance] metricSnapshot:TRUE]; [strongDelegate controller:strongController commissioningComplete:nsError nodeID:nodeID metrics:metrics]; } else { [strongDelegate controller:strongController commissioningComplete:nsError nodeID:nodeID]; diff --git a/src/darwin/Framework/CHIP/MTRDeviceControllerFactory.mm b/src/darwin/Framework/CHIP/MTRDeviceControllerFactory.mm index 0430558e8a4b32..d89df5a4b09c4d 100644 --- a/src/darwin/Framework/CHIP/MTRDeviceControllerFactory.mm +++ b/src/darwin/Framework/CHIP/MTRDeviceControllerFactory.mm @@ -39,6 +39,7 @@ #import "MTRFabricInfo_Internal.h" #import "MTRFramework.h" #import "MTRLogging_Internal.h" +#import "MTRMetricsCollector.h" #import "MTROTAProviderDelegateBridge.h" #import "MTROperationalBrowser.h" #import "MTRP256KeypairBridge.h" @@ -349,6 +350,8 @@ - (void)cleanupStartupObjects } _diagnosticLogsDownloader = nil; + + ShutdownMetricsCollection(); } - (CHIP_ERROR)_initFabricTable:(FabricTable &)fabricTable @@ -414,6 +417,10 @@ - (BOOL)startControllerFactory:(MTRDeviceControllerFactoryParams *)startupParams return YES; } + // Register any tracing backends. This has to be done before starting the event loop to run registering + // the tracing backend in the right queue context + StartupMetricsCollection(); + DeviceLayer::PlatformMgrImpl().StartEventLoopTask(); __block CHIP_ERROR errorCode = CHIP_NO_ERROR; diff --git a/src/darwin/Framework/CHIP/MTRFramework.mm b/src/darwin/Framework/CHIP/MTRFramework.mm index e6a0e672955be3..3eff8a1b8dbfc3 100644 --- a/src/darwin/Framework/CHIP/MTRFramework.mm +++ b/src/darwin/Framework/CHIP/MTRFramework.mm @@ -15,6 +15,7 @@ */ #import "MTRFramework.h" +#import "MTRMetricsCollector.h" #include #include @@ -34,5 +35,8 @@ void MTRFrameworkInit() // Suppress CHIP logging until we actually need it for redirection // (see MTRSetLogCallback()). Logging to os_log is always enabled. chip::Logging::SetLogFilter(chip::Logging::kLogCategory_None); + + // Startup metrics collection and tracing framework + StartupMetricsCollection(); }); } diff --git a/src/darwin/Framework/CHIP/MTRMetrics.h b/src/darwin/Framework/CHIP/MTRMetrics.h index 81161ee049bedd..483de01df3ebd6 100644 --- a/src/darwin/Framework/CHIP/MTRMetrics.h +++ b/src/darwin/Framework/CHIP/MTRMetrics.h @@ -21,14 +21,28 @@ NS_ASSUME_NONNULL_BEGIN /** - * A representation of metrics data for an operation. + * A representation of a collection of metrics data for an operation. */ MTR_NEWLY_AVAILABLE @interface MTRMetrics : NSObject +- (instancetype)init NS_UNAVAILABLE; ++ (instancetype)new NS_UNAVAILABLE; + +/** + * @brief Returns the names of all the metrics data items collected. + */ @property (nonatomic, readonly, copy) NSArray * allKeys; +/** + * @brief Returns metric object corresponding to the metric identified by its key + * + * @param [in] key Name of the metric + * + * @return An object containing the metric data, nil if key is invalid + */ - (nullable id)valueForKey:(NSString *)key; @end + NS_ASSUME_NONNULL_END diff --git a/src/darwin/Framework/CHIP/MTRMetrics.mm b/src/darwin/Framework/CHIP/MTRMetrics.mm index c1135c1cfbc0b6..8c338b70285e08 100644 --- a/src/darwin/Framework/CHIP/MTRMetrics.mm +++ b/src/darwin/Framework/CHIP/MTRMetrics.mm @@ -16,16 +16,24 @@ */ #import "MTRLogging_Internal.h" #import "MTRMetrics_Internal.h" +#include #import +#include @implementation MTRMetrics { NSMutableDictionary * _metricsData; } - (instancetype)init +{ + NSAssert(false, @"'init' unavailable, use initWithCapacity: instead"); + return nil; +} + +- (instancetype)initWithCapacity:(NSUInteger)numItems { if (self = [super init]) { - _metricsData = [NSMutableDictionary dictionary]; + _metricsData = [NSMutableDictionary dictionaryWithCapacity:numItems]; } return self; } diff --git a/src/darwin/Framework/CHIP/MTRMetricsCollector.h b/src/darwin/Framework/CHIP/MTRMetricsCollector.h new file mode 100644 index 00000000000000..71d0afc26c039a --- /dev/null +++ b/src/darwin/Framework/CHIP/MTRMetricsCollector.h @@ -0,0 +1,59 @@ +/** + * + * Copyright (c) 2024 Project CHIP Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include +#import + +NS_ASSUME_NONNULL_BEGIN + +/** + * This function initializes any backend required to collect metrics data. + */ +void StartupMetricsCollection(); + +/** + * This function shuts down any backend created to collect metrics data. + */ +void ShutdownMetricsCollection(); + +/** + * A representation of metrics data for an operation. + */ +@interface MTRMetricsCollector : NSObject + +- (instancetype)init NS_UNAVAILABLE; ++ (instancetype)new NS_UNAVAILABLE; + +/** + * Return the singleton MTRMetricsCollector to vend MTRMetrics snapshots + */ ++ (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. + * + * @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; + +@end + +NS_ASSUME_NONNULL_END diff --git a/src/darwin/Framework/CHIP/MTRMetricsCollector.mm b/src/darwin/Framework/CHIP/MTRMetricsCollector.mm new file mode 100644 index 00000000000000..6387738a7c13c8 --- /dev/null +++ b/src/darwin/Framework/CHIP/MTRMetricsCollector.mm @@ -0,0 +1,256 @@ +/** + * + * Copyright (c) 2024 Project CHIP Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#import "MTRMetricsCollector.h" +#import "MTRLogging_Internal.h" +#include "MTRMetrics_Internal.h" +#import +#include +#include +#include +#include + +using MetricEvent = chip::Tracing::MetricEvent; + +static NSString * kMTRMetricDataValueKey = @"value"; +static NSString * kMTRMetricDataTimepointKey = @"time_point"; +static NSString * kMTRMetricDataDurationKey = @"duration_us"; + +@implementation MTRMetricsData { + chip::System::Clock::Microseconds64 _timePoint; + chip::System::Clock::Microseconds64 _duration; +} + +- (instancetype)initWithMetricEvent:(const MetricEvent &)event +{ + if (!(self = [super init])) { + return nil; + } + + using ValueType = MetricEvent::Value::Type; + switch (event.ValueType()) { + case ValueType::kInt32: + _value = [NSNumber numberWithInteger:event.ValueInt32()]; + break; + case ValueType::kUInt32: + _value = [NSNumber numberWithInteger:event.ValueUInt32()]; + break; + case ValueType::kChipErrorCode: + _value = [NSNumber numberWithInteger:event.ValueErrorCode()]; + break; + case ValueType::kUndefined: + default: + _value = nil; + } + + _timePoint = chip::System::SystemClock().GetMonotonicMicroseconds64(); + _duration = chip::System::Clock::Microseconds64(0); + return self; +} + +- (void)setDurationFromMetricData:(MTRMetricsData *)fromData +{ + _duration = _timePoint - fromData->_timePoint; +} + +- (NSNumber *)timePointMicroseconds +{ + return [NSNumber numberWithUnsignedLongLong:_timePoint.count()]; +} + +- (NSNumber *)durationMicroseconds +{ + return [NSNumber numberWithUnsignedLongLong:_duration.count()]; +} + +- (NSString *)description +{ + return [NSString stringWithFormat:@"MTRMetricsData: Value = %@, TimePoint = %@, Duration = %@ us", self.value, self.timePointMicroseconds, self.durationMicroseconds]; +} + +- (NSDictionary *)toDictionary +{ + NSMutableDictionary * dictRepresentation = [NSMutableDictionary dictionary]; + if (self.value) { + [dictRepresentation setValue:self.value forKey:kMTRMetricDataValueKey]; + } + if (auto tmPt = self.timePointMicroseconds) { + [dictRepresentation setValue:tmPt forKey:kMTRMetricDataTimepointKey]; + } + if (auto duration = self.durationMicroseconds) { + [dictRepresentation setValue:duration forKey:kMTRMetricDataDurationKey]; + } + return dictRepresentation; +} + +@end + +@interface MTRMetricsCollector () + +- (void)registerTracingBackend; + +- (void)unregisterTracingBackend; + +@end + +void StartupMetricsCollection() +{ + if ([MTRMetricsCollector sharedInstance]) { + MTR_LOG_INFO("Initialized metrics collection backend for Darwin"); + + [[MTRMetricsCollector sharedInstance] registerTracingBackend]; + } +} + +void ShutdownMetricsCollection() +{ + [[MTRMetricsCollector sharedInstance] unregisterTracingBackend]; +} + +@implementation MTRMetricsCollector { + os_unfair_lock _lock; + NSMutableDictionary * _metricsDataCollection; + chip::Tracing::signposts::DarwinTracingBackend _tracingBackend; +} + ++ (instancetype)sharedInstance +{ + static MTRMetricsCollector * singleton = nil; + static dispatch_once_t onceToken; + dispatch_once(&onceToken, ^{ + // Initialize the singleton and register the event handler + singleton = [[MTRMetricsCollector alloc] init]; + if (singleton) { + singleton->_tracingBackend.SetMetricEventHandler(^(MetricEvent event) { + if (singleton) { + [singleton handleMetricEvent:event]; + } + }); + } + }); + return singleton; +} + +- (instancetype)init +{ + if (!(self = [super init])) { + return nil; + } + _lock = OS_UNFAIR_LOCK_INIT; + _metricsDataCollection = [NSMutableDictionary dictionary]; + return self; +} + +- (void)registerTracingBackend +{ + std::lock_guard lock(_lock); + chip::Tracing::Register(_tracingBackend); + MTR_LOG_INFO("Registered tracing backend with the registry"); +} + +- (void)unregisterTracingBackend +{ + std::lock_guard lock(_lock); + chip::Tracing::Unregister(_tracingBackend); + MTR_LOG_INFO("Unregistered tracing backend with the registry"); +} + +static inline NSString * suffixNameForMetricType(MetricEvent::Type type) +{ + switch (type) { + case MetricEvent::Type::kBeginEvent: + return @"-begin"; + case MetricEvent::Type::kEndEvent: + return @"-end"; + case MetricEvent::Type::kInstantEvent: + return @"-instant"; + } +} + +static inline NSString * suffixNameForMetric(const MetricEvent & event) +{ + return suffixNameForMetricType(event.type()); +} + +- (void)handleMetricEvent:(MetricEvent)event +{ + std::lock_guard lock(_lock); + + using ValueType = MetricEvent::Value::Type; + switch (event.ValueType()) { + case ValueType::kInt32: + MTR_LOG_INFO("Received metric event, key: %s, type: %d, value: %d", event.key(), event.type(), event.ValueInt32()); + break; + case ValueType::kUInt32: + MTR_LOG_INFO("Received metric event, key: %s, type: %d, value: %u", event.key(), event.type(), event.ValueUInt32()); + break; + case ValueType::kChipErrorCode: + MTR_LOG_INFO("Received metric event, key: %s, type: %d, error value: %u", event.key(), event.type(), event.ValueErrorCode()); + break; + case ValueType::kUndefined: + MTR_LOG_INFO("Received metric event, key: %s, type: %d, value: nil", event.key(), event.type()); + break; + default: + MTR_LOG_INFO("Received metric event, key: %s, type: %d, unknown value", event.key(), event.type()); + return; + } + + // Create the new metric key based event type + auto metricsKey = [NSString stringWithFormat:@"%s%@", event.key(), suffixNameForMetric(event)]; + MTRMetricsData * data = [[MTRMetricsData alloc] initWithMetricEvent:event]; + + // If End event, compute its duration using the Begin event + if (event.type() == MetricEvent::Type::kEndEvent) { + auto metricsBeginKey = [NSString stringWithFormat:@"%s%@", event.key(), suffixNameForMetricType(MetricEvent::Type::kBeginEvent)]; + MTRMetricsData * beginMetric = _metricsDataCollection[metricsBeginKey]; + if (beginMetric) { + [data setDurationFromMetricData:beginMetric]; + } else { + // Unbalanced end + MTR_LOG_ERROR("Unable to find Begin event corresponding to Metric Event: %s", event.key()); + } + } + + [_metricsDataCollection setValue:data forKey:metricsKey]; + + // If the event is a begin or end event, implicitly emit a corresponding instant event + if (event.type() == MetricEvent::Type::kBeginEvent || event.type() == MetricEvent::Type::kEndEvent) { + MetricEvent instantEvent(MetricEvent::Type::kInstantEvent, event.key()); + data = [[MTRMetricsData alloc] initWithMetricEvent:instantEvent]; + metricsKey = [NSString stringWithFormat:@"%s%@", event.key(), suffixNameForMetric(instantEvent)]; + [_metricsDataCollection setValue:data forKey:metricsKey]; + } +} + +- (MTRMetrics *)metricSnapshot:(BOOL)resetCollection +{ + std::lock_guard lock(_lock); + + // Copy the MTRMetrics as NSDictionary + MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:[_metricsDataCollection count]]; + for (NSString * key in _metricsDataCollection) { + [metrics setValue:[_metricsDataCollection[key] toDictionary] forKey:key]; + } + + // Clear curent stats, if specified + if (resetCollection) { + [_metricsDataCollection removeAllObjects]; + } + return metrics; +} + +@end diff --git a/src/darwin/Framework/CHIP/MTRMetrics_Internal.h b/src/darwin/Framework/CHIP/MTRMetrics_Internal.h index 3e69c79dd53802..757ff0731ada0c 100644 --- a/src/darwin/Framework/CHIP/MTRMetrics_Internal.h +++ b/src/darwin/Framework/CHIP/MTRMetrics_Internal.h @@ -15,13 +15,33 @@ * limitations under the License. */ #import "MTRMetrics.h" +#include NS_ASSUME_NONNULL_BEGIN -#define MTRMetricCommissioningStatusKey @"com.matter.metric.commissioningStatus" +/** + * A representation of a metric data for an operation. + */ +@interface MTRMetricsData : NSObject + +// Value for the metric. This can be null if the metric is just a fire event with no value +@property (nonatomic, nullable, readonly, copy) NSNumber * value; + +// Relative time point at which the metric was emitted. This may be null. +@property (nonatomic, nullable, readonly, copy) NSNumber * timePointMicroseconds; + +// During for the event. This may be null. +@property (nonatomic, nullable, readonly, copy) NSNumber * durationMicroseconds; + +// Convert contents to a dictionary +- (NSDictionary *)toDictionary; + +@end @interface MTRMetrics () +- (instancetype)initWithCapacity:(NSUInteger)numItems; + - (void)setValue:(id _Nullable)value forKey:(NSString *)key; - (void)removeValueForKey:(NSString *)key; diff --git a/src/darwin/Framework/CHIPTests/MTRMetricsTests.m b/src/darwin/Framework/CHIPTests/MTRMetricsTests.m index ed5de20b5c433b..696f55bef89df4 100644 --- a/src/darwin/Framework/CHIPTests/MTRMetricsTests.m +++ b/src/darwin/Framework/CHIPTests/MTRMetricsTests.m @@ -49,7 +49,7 @@ - (void)test000_SetUp - (void)test001_TestAllKeys { - MTRMetrics * metrics = [MTRMetrics new]; + MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:4]; [metrics setValue:@"metricsCounter1" forKey:@"com.matter.metrics.counter1"]; [metrics setValue:@"metricsCounter2" forKey:@"com.matter.metrics.counter2"]; [metrics setValue:@"metricsCounter3" forKey:@"com.matter.metrics.counter3"]; @@ -65,7 +65,7 @@ - (void)test001_TestAllKeys } - (void)test002_TestOneKey { - MTRMetrics * metrics = [MTRMetrics new]; + MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:1]; [metrics setValue:@"metricsCounter1" forKey:@"com.matter.metrics.counter1"]; NSArray * keys = [metrics allKeys]; @@ -75,7 +75,7 @@ - (void)test002_TestOneKey - (void)test003_TestMultipleKeys { - MTRMetrics * metrics = [MTRMetrics new]; + MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:3]; [metrics setValue:@"metricsCounter1" forKey:@"com.matter.metrics.counter1"]; [metrics setValue:@"metricsCounter2" forKey:@"com.matter.metrics.counter2"]; [metrics setValue:[NSError errorWithDomain:MTRErrorDomain code:MTRErrorCodeInvalidState userInfo:nil] forKey:@"com.matter.metrics.counter3"]; @@ -90,7 +90,7 @@ - (void)test003_TestMultipleKeys - (void)test004_TestValueForKey { - MTRMetrics * metrics = [MTRMetrics new]; + MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:1]; [metrics setValue:@"metricsCounter1" forKey:@"com.matter.metrics.counter1"]; XCTAssertEqualObjects([metrics valueForKey:@"com.matter.metrics.counter1"], @"metricsCounter1"); @@ -98,7 +98,7 @@ - (void)test004_TestValueForKey - (void)test005_TestMultipleValueForKeys { - MTRMetrics * metrics = [MTRMetrics new]; + MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:3]; [metrics setValue:@"metricsCounter1" forKey:@"com.matter.metrics.counter1"]; [metrics setValue:@"metricsCounter2" forKey:@"com.matter.metrics.counter2"]; [metrics setValue:[NSError errorWithDomain:MTRErrorDomain code:MTRErrorCodeInvalidState userInfo:nil] forKey:@"com.matter.metrics.counter3"]; @@ -110,7 +110,7 @@ - (void)test005_TestMultipleValueForKeys - (void)test006_TestValueRemoval { - MTRMetrics * metrics = [MTRMetrics new]; + MTRMetrics * metrics = [[MTRMetrics alloc] initWithCapacity:2]; [metrics setValue:@"metricsCounter1" forKey:@"com.matter.metrics.counter1"]; [metrics setValue:@"metricsCounter2" forKey:@"com.matter.metrics.counter2"]; diff --git a/src/darwin/Framework/Matter.xcodeproj/project.pbxproj b/src/darwin/Framework/Matter.xcodeproj/project.pbxproj index a49b33fa3a1ea4..698fe2ad47114a 100644 --- a/src/darwin/Framework/Matter.xcodeproj/project.pbxproj +++ b/src/darwin/Framework/Matter.xcodeproj/project.pbxproj @@ -266,6 +266,9 @@ 88EBF8CE27FABDD500686BC1 /* MTRDeviceAttestationDelegate.h in Headers */ = {isa = PBXBuildFile; fileRef = 88EBF8CB27FABDD500686BC1 /* MTRDeviceAttestationDelegate.h */; settings = {ATTRIBUTES = (Public, ); }; }; 88EBF8CF27FABDD500686BC1 /* MTRDeviceAttestationDelegateBridge.mm in Sources */ = {isa = PBXBuildFile; fileRef = 88EBF8CC27FABDD500686BC1 /* MTRDeviceAttestationDelegateBridge.mm */; }; 88EBF8D027FABDD500686BC1 /* MTRDeviceAttestationDelegateBridge.h in Headers */ = {isa = PBXBuildFile; fileRef = 88EBF8CD27FABDD500686BC1 /* MTRDeviceAttestationDelegateBridge.h */; }; + 88FA798D2B7B257100CD4B6F /* MTRMetricsCollector.h in Headers */ = {isa = PBXBuildFile; fileRef = 88FA798B2B7B257100CD4B6F /* MTRMetricsCollector.h */; }; + 88FA798E2B7B257100CD4B6F /* MTRMetricsCollector.mm in Sources */ = {isa = PBXBuildFile; fileRef = 88FA798C2B7B257100CD4B6F /* MTRMetricsCollector.mm */; }; + 88FA79902B7BE42500CD4B6F /* MTRMetricsCollector.mm in Sources */ = {isa = PBXBuildFile; fileRef = 88FA798C2B7B257100CD4B6F /* MTRMetricsCollector.mm */; }; 93B2CF9A2B56E45C00E4D187 /* MTRClusterNames.mm in Sources */ = {isa = PBXBuildFile; fileRef = 93B2CF992B56E45C00E4D187 /* MTRClusterNames.mm */; }; 93E610AA2B626E290077F02A /* MTRClusterNames.h in Headers */ = {isa = PBXBuildFile; fileRef = 93E610A92B626E290077F02A /* MTRClusterNames.h */; settings = {ATTRIBUTES = (Public, ); }; }; 991DC0842475F45400C13860 /* MTRDeviceController.h in Headers */ = {isa = PBXBuildFile; fileRef = 991DC0822475F45400C13860 /* MTRDeviceController.h */; settings = {ATTRIBUTES = (Public, ); }; }; @@ -664,6 +667,8 @@ 88EBF8CB27FABDD500686BC1 /* MTRDeviceAttestationDelegate.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = MTRDeviceAttestationDelegate.h; sourceTree = ""; }; 88EBF8CC27FABDD500686BC1 /* MTRDeviceAttestationDelegateBridge.mm */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.objcpp; path = MTRDeviceAttestationDelegateBridge.mm; sourceTree = ""; }; 88EBF8CD27FABDD500686BC1 /* MTRDeviceAttestationDelegateBridge.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = MTRDeviceAttestationDelegateBridge.h; sourceTree = ""; }; + 88FA798B2B7B257100CD4B6F /* MTRMetricsCollector.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = MTRMetricsCollector.h; sourceTree = ""; }; + 88FA798C2B7B257100CD4B6F /* MTRMetricsCollector.mm */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.objcpp; path = MTRMetricsCollector.mm; sourceTree = ""; }; 93B2CF992B56E45C00E4D187 /* MTRClusterNames.mm */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.objcpp; path = MTRClusterNames.mm; sourceTree = ""; }; 93E610A92B626E290077F02A /* MTRClusterNames.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = MTRClusterNames.h; sourceTree = ""; }; 991DC0822475F45400C13860 /* MTRDeviceController.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; path = MTRDeviceController.h; sourceTree = ""; }; @@ -1160,6 +1165,8 @@ B202528F2459E34F00F97062 /* CHIP */ = { isa = PBXGroup; children = ( + 88FA798B2B7B257100CD4B6F /* MTRMetricsCollector.h */, + 88FA798C2B7B257100CD4B6F /* MTRMetricsCollector.mm */, 88E6C9442B6334ED001A1FE0 /* MTRMetrics_Internal.h */, 88E6C9432B6334ED001A1FE0 /* MTRMetrics.h */, 88E6C9452B6334ED001A1FE0 /* MTRMetrics.mm */, @@ -1518,6 +1525,7 @@ 2C222AD0255C620600E446B9 /* MTRBaseDevice.h in Headers */, 7596A84F2877E6A9004DAE0E /* MTRCluster_Internal.h in Headers */, 991DC0842475F45400C13860 /* MTRDeviceController.h in Headers */, + 88FA798D2B7B257100CD4B6F /* MTRMetricsCollector.h in Headers */, 88E6C9462B6334ED001A1FE0 /* MTRMetrics.h in Headers */, AF1CB86E2874B03B00865A96 /* MTROTAProviderDelegate.h in Headers */, 51D0B1402B61B3A4006E3511 /* MTRServerCluster.h in Headers */, @@ -1739,6 +1747,7 @@ 039546A62991E151006D42A8 /* InteractionModel.cpp in Sources */, B45373E72A9FEBA400807602 /* parsers.c in Sources */, B4FCD5722B603A6300832859 /* DownloadLogCommand.mm in Sources */, + 88FA79902B7BE42500CD4B6F /* MTRMetricsCollector.mm in Sources */, B45373BF2A9FEA9100807602 /* adopt.c in Sources */, B45373F32A9FEC1A00807602 /* server-ws.c in Sources */, 03F430AA2994113500166449 /* sysunix.c in Sources */, @@ -1893,6 +1902,7 @@ 5A6FEC9827B5C6AF00F25F42 /* MTRDeviceOverXPC.mm in Sources */, 514654492A72F9DF00904E61 /* MTRDemuxingStorage.mm in Sources */, 1E4D655229C30A8700BC3478 /* MTRCommissionableBrowser.mm in Sources */, + 88FA798E2B7B257100CD4B6F /* MTRMetricsCollector.mm in Sources */, 3DA1A3562ABAB3B4004F0BB9 /* MTRAsyncWorkQueue.mm in Sources */, 51D0B1272B617246006E3511 /* MTRServerEndpoint.mm in Sources */, 3DECCB722934AFE200585AEC /* MTRLogging.mm in Sources */, diff --git a/src/lib/support/CodeUtils.h b/src/lib/support/CodeUtils.h index 58094a01731c37..2b47538b8faebf 100644 --- a/src/lib/support/CodeUtils.h +++ b/src/lib/support/CodeUtils.h @@ -362,10 +362,10 @@ constexpr inline const _T & max(const _T & a, const _T & b) } while (false) /** - * @def SuccessOrExit(aStatus) + * @def SuccessOrExit(error) * * @brief - * This checks for the specified status, which is expected to + * This checks for the specified error, which is expected to * commonly be successful (CHIP_NO_ERROR), and branches to * the local label 'exit' if the status is unsuccessful. * @@ -387,10 +387,10 @@ constexpr inline const _T & max(const _T & a, const _T & b) * } * @endcode * - * @param[in] aStatus A scalar status to be evaluated against zero (0). + * @param[in] error A ChipError object to be evaluated against success (CHIP_NO_ERROR). * */ -#define SuccessOrExit(aStatus) nlEXPECT(::chip::ChipError::IsSuccess((aStatus)), exit) +#define SuccessOrExit(error) nlEXPECT(::chip::ChipError::IsSuccess((error)), exit) /** * @def VerifyOrExit(aCondition, anAction) diff --git a/src/platform/Darwin/BUILD.gn b/src/platform/Darwin/BUILD.gn index 11372cb5f4c627..321076da241cb5 100644 --- a/src/platform/Darwin/BUILD.gn +++ b/src/platform/Darwin/BUILD.gn @@ -97,6 +97,7 @@ static_library("Darwin") { deps = [ ":logging", + ":tracing", "${chip_root}/src/lib/dnssd:platform_header", "${chip_root}/src/platform/logging:headers", "${chip_root}/src/setup_payload", @@ -131,6 +132,18 @@ static_library("Darwin") { } } +source_set("tracing") { + sources = [ + "Tracing.h", + "Tracing.mm", + ] + + deps = [ + ":logging", + "${chip_root}/src/tracing", + ] +} + static_library("logging") { sources = [ "Logging.h", diff --git a/src/platform/Darwin/Tracing.h b/src/platform/Darwin/Tracing.h new file mode 100644 index 00000000000000..cefc5c326fc3d5 --- /dev/null +++ b/src/platform/Darwin/Tracing.h @@ -0,0 +1,77 @@ +/* + * + * Copyright (c) 2024 Project CHIP Authors + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include + +#define MATTER_TRACE_BEGIN(label, group) os_signpost_interval_begin(__DARWIN_MATTER_SIGNPOST_LOGGER(), OS_SIGNPOST_ID_EXCLUSIVE, group "-" label) +#define MATTER_TRACE_END(label, group) os_signpost_interval_end(__DARWIN_MATTER_SIGNPOST_LOGGER(), OS_SIGNPOST_ID_EXCLUSIVE, group "-" label) +#define MATTER_TRACE_INSTANT(label, group) os_signpost_event_emit(__DARWIN_MATTER_SIGNPOST_LOGGER(), OS_SIGNPOST_ID_EXCLUSIVE, group "-" label) + +#define MATTER_TRACE_COUNTER(label) \ + do { \ + static unsigned int count##_label = 0; \ + os_signpost_event_emit(__DARWIN_MATTER_SIGNPOST_LOGGER(), OS_SIGNPOST_ID_EXCLUSIVE, label, "%u", ++count##_label); \ + } while (0) + +#define _CONCAT_IMPL(a, b) a##b +#define _MACRO_CONCAT(a, b) _CONCAT_IMPL(a, b) + +#define MATTER_TRACE_SCOPE(label, group) ::chip::Tracing::signposts::Scoped _MACRO_CONCAT(_trace_scope, __COUNTER__)(label, group) + +#define MATTER_SDK_SIGNPOST_NAME "com.csa.matter.signpost" +#define __DARWIN_MATTER_SIGNPOST_LOGGER() chip::Tracing::signposts::GetMatterSignpostLogger() + +namespace chip { +namespace Tracing { + namespace signposts { + + os_log_t GetMatterSignpostLogger(); + + class Scoped { + public: + inline Scoped(const char * label, const char * group) + : mLabel(label) + , mGroup(group) + { + os_signpost_interval_begin(__DARWIN_MATTER_SIGNPOST_LOGGER(), OS_SIGNPOST_ID_EXCLUSIVE, MATTER_SDK_SIGNPOST_NAME, "%s-%s", group, label); + } + inline ~Scoped() { os_signpost_interval_end(__DARWIN_MATTER_SIGNPOST_LOGGER(), OS_SIGNPOST_ID_EXCLUSIVE, MATTER_SDK_SIGNPOST_NAME, "%s-%s", mGroup, mLabel); } + + private: + const char * mLabel; + const char * mGroup; + }; + + class DarwinTracingBackend : public ::chip::Tracing::Backend { + public: + DarwinTracingBackend(); + + typedef void (^MetricEventHandler)(MetricEvent event); + + void SetMetricEventHandler(MetricEventHandler callback); + void LogMetricEvent(const MetricEvent & event) override; + + private: + MetricEventHandler mClientCallback; + }; + + } // namespace signposts +} // namespace Tracing +} // namespace chip diff --git a/src/platform/Darwin/Tracing.mm b/src/platform/Darwin/Tracing.mm new file mode 100644 index 00000000000000..a729c32e8079a1 --- /dev/null +++ b/src/platform/Darwin/Tracing.mm @@ -0,0 +1,55 @@ +/* + * + * Copyright (c) 2024 Project CHIP Authors + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#import +#include +#include + +namespace chip { +namespace Tracing { + namespace signposts { + os_log_t GetMatterSignpostLogger() + { + static dispatch_once_t onceToken; + static os_log_t logger; + dispatch_once(&onceToken, ^{ + logger = os_log_create("com.csa.matter.signposts", "com.csa.matter.sdk"); + }); + return logger; + } + + DarwinTracingBackend::DarwinTracingBackend() + : mClientCallback(nullptr) + { + } + + void DarwinTracingBackend::SetMetricEventHandler(MetricEventHandler callback) + { + mClientCallback = callback; + } + + void DarwinTracingBackend::LogMetricEvent(const MetricEvent & event) + { + // Pass along to the client to handle the event + if (mClientCallback) { + mClientCallback(event); + } + } + + } // namespace signposts +} // namespace Tracing +} // namespace chip diff --git a/src/tracing/BUILD.gn b/src/tracing/BUILD.gn index 84af8b09ef2449..cdb50a710c9c00 100644 --- a/src/tracing/BUILD.gn +++ b/src/tracing/BUILD.gn @@ -36,12 +36,16 @@ static_library("tracing") { sources = [ "backend.h", "log_declares.h", + "metric_event.h", + "metric_keys.h", + "metric_macros.h", "registry.cpp", "registry.h", ] public_deps = [ ":tracing_buildconfig", + "${chip_root}/src/lib/core:error", "${chip_root}/src/lib/support", ] } diff --git a/src/tracing/backend.h b/src/tracing/backend.h index c57e97ddd27638..9bc4e8bd096ebd 100644 --- a/src/tracing/backend.h +++ b/src/tracing/backend.h @@ -64,13 +64,13 @@ class Backend : public ::chip::IntrusiveListNodeBase<> virtual void TraceInstant(const char * label, const char * group) {} virtual void TraceCounter(const char * label) {} - virtual void TraceMetric(const char * label, int32_t value) {} virtual void LogMessageSend(MessageSendInfo &) { TraceInstant("MessageSent", "Messaging"); } virtual void LogMessageReceived(MessageReceivedInfo &) { TraceInstant("MessageReceived", "Messaging"); } virtual void LogNodeLookup(NodeLookupInfo &) { TraceInstant("Lookup", "DNSSD"); } virtual void LogNodeDiscovered(NodeDiscoveredInfo &) { TraceInstant("Node Discovered", "DNSSD"); } virtual void LogNodeDiscoveryFailed(NodeDiscoveryFailedInfo &) { TraceInstant("Discovery Failed", "DNSSD"); } + virtual void LogMetricEvent(const MetricEvent &) { TraceInstant("Metric Event", "Metric"); } }; } // namespace Tracing diff --git a/src/tracing/darwin/BUILD.gn b/src/tracing/darwin/BUILD.gn new file mode 100644 index 00000000000000..3bd9b7685b594e --- /dev/null +++ b/src/tracing/darwin/BUILD.gn @@ -0,0 +1,25 @@ +# Copyright (c) 2024 Project CHIP Authors +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import("//build_overrides/build.gni") +import("//build_overrides/chip.gni") + +config("tracing") { + include_dirs = [ "include" ] +} + +source_set("darwin_tracing") { + public = [ "include/matter/tracing/macros_impl.h" ] + public_configs = [ ":tracing" ] +} diff --git a/src/tracing/darwin/include/matter/tracing/macros_impl.h b/src/tracing/darwin/include/matter/tracing/macros_impl.h new file mode 100644 index 00000000000000..536618dc2875b2 --- /dev/null +++ b/src/tracing/darwin/include/matter/tracing/macros_impl.h @@ -0,0 +1,25 @@ +/* + * + * Copyright (c) 2024 Project CHIP Authors + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +/* Ensure we do not have double tracing macros defined */ +#if defined(MATTER_TRACE_BEGIN) +#error "Tracing macros seem to be double defined" +#endif + +#include diff --git a/src/tracing/esp32_trace/esp32_tracing.cpp b/src/tracing/esp32_trace/esp32_tracing.cpp index 6193587be49c7d..db5f09ee9a751c 100644 --- a/src/tracing/esp32_trace/esp32_tracing.cpp +++ b/src/tracing/esp32_trace/esp32_tracing.cpp @@ -24,6 +24,7 @@ #include #include #include +#include namespace chip { namespace Tracing { @@ -154,16 +155,38 @@ void ESP32Backend::TraceCounter(const char * label) ::Insights::ESPInsightsCounter::GetInstance(label)->ReportMetrics(); } -void ESP32Backend::TraceMetric(const char * label, int32_t value) +void ESP32Backend::LogMetricEvent(const MetricEvent & event) { if (!mRegistered) { - esp_diag_metrics_register("SYS_MTR" /*Tag of metrics */, label /* Unique key 8 */, label /* label displayed on dashboard */, - "insights.mtr" /* hierarchical path */, ESP_DIAG_DATA_TYPE_INT /* data_type */); + esp_diag_metrics_register("SYS_MTR" /*Tag of metrics */, event.key() /* Unique key 8 */, + event.key() /* label displayed on dashboard */, "insights.mtr" /* hierarchical path */, + ESP_DIAG_DATA_TYPE_INT /* data_type */); mRegistered = true; } - ESP_LOGI("mtr", "The value of %s is %ld ", label, value); - esp_diag_metrics_add_int(label, value); + + using ValueType = MetricEvent::Value::Type; + switch (event.ValueType()) + { + case ValueType::kInt32: + ESP_LOGI("mtr", "The value of %s is %ld ", event.key(), event.ValueInt32()); + esp_diag_metrics_add_int(event.key(), event.ValueInt32()); + break; + case ValueType::kUInt32: + ESP_LOGI("mtr", "The value of %s is %lu ", event.key(), event.ValueUInt32()); + esp_diag_metrics_add_uint(event.key(), event.ValueUInt32()); + break; + case ValueType::kChipErrorCode: + ESP_LOGI("mtr", "The value of %s is error with code %lu ", event.key(), event.ValueErrorCode()); + esp_diag_metrics_add_uint(event.key(), event.ValueErrorCode()); + break; + case ValueType::kUndefined: + ESP_LOGI("mtr", "The value of %s is undefined", event.key()); + break; + default: + ESP_LOGI("mtr", "The value of %s is of an UNKNOWN TYPE", event.key()); + break; + } } void ESP32Backend::TraceBegin(const char * label, const char * group) diff --git a/src/tracing/esp32_trace/esp32_tracing.h b/src/tracing/esp32_trace/esp32_tracing.h index 3eb127c1d3367f..2e08e69d616158 100644 --- a/src/tracing/esp32_trace/esp32_tracing.h +++ b/src/tracing/esp32_trace/esp32_tracing.h @@ -29,7 +29,6 @@ class ESP32Backend : public ::chip::Tracing::Backend void TraceInstant(const char * label, const char * group) override; void TraceCounter(const char * label) override; - void TraceMetric(const char * label, int32_t value) override; void LogMessageSend(MessageSendInfo &) override; void LogMessageReceived(MessageReceivedInfo &) override; @@ -37,6 +36,7 @@ class ESP32Backend : public ::chip::Tracing::Backend void LogNodeLookup(NodeLookupInfo &) override; void LogNodeDiscovered(NodeDiscoveredInfo &) override; void LogNodeDiscoveryFailed(NodeDiscoveryFailedInfo &) override; + void LogMetricEvent(const MetricEvent &) override; private: bool mRegistered = false; diff --git a/src/tracing/esp32_trace/include/matter/tracing/macros_impl.h b/src/tracing/esp32_trace/include/matter/tracing/macros_impl.h index 8ebde173d8297b..b95c20754237a1 100644 --- a/src/tracing/esp32_trace/include/matter/tracing/macros_impl.h +++ b/src/tracing/esp32_trace/include/matter/tracing/macros_impl.h @@ -29,7 +29,6 @@ #define MATTER_TRACE_END(label, group) ::chip::Tracing::Internal::End(label, group) #define MATTER_TRACE_INSTANT(label, group) ::chip::Tracing::Internal::Instant(label, group) #define MATTER_TRACE_COUNTER(label) ::chip::Tracing::Internal::Counter(label) -#define MATTER_TRACE_METRIC(label, value) ::chip::Tracing::Internal::Metric(label, value) namespace chip { namespace Tracing { diff --git a/src/tracing/json/json_tracing.cpp b/src/tracing/json/json_tracing.cpp index 64627f079d04dd..91b4474388ecd0 100644 --- a/src/tracing/json/json_tracing.cpp +++ b/src/tracing/json/json_tracing.cpp @@ -24,6 +24,7 @@ #include #include #include +#include #include #include @@ -295,11 +296,31 @@ void JsonBackend::TraceCounter(const char * label) OutputValue(value); } -void JsonBackend::TraceMetric(const char * label, int32_t val) +void JsonBackend::LogMetricEvent(const MetricEvent & event) { ::Json::Value value; - value["label"] = label; - value["value"] = val; + + value["label"] = event.key(); + + using ValueType = MetricEvent::Value::Type; + switch (event.ValueType()) + { + case ValueType::kInt32: + value["value"] = event.ValueInt32(); + break; + case ValueType::kUInt32: + value["value"] = event.ValueUInt32(); + break; + case ValueType::kChipErrorCode: + value["value"] = event.ValueErrorCode(); + break; + case ValueType::kUndefined: + value["value"] = ::Json::Value(); + break; + default: + value["value"] = "UNKNOWN"; + break; + } OutputValue(value); } diff --git a/src/tracing/json/json_tracing.h b/src/tracing/json/json_tracing.h index e8ad8ee5894b03..14f3d163a04c46 100644 --- a/src/tracing/json/json_tracing.h +++ b/src/tracing/json/json_tracing.h @@ -52,12 +52,12 @@ class JsonBackend : public ::chip::Tracing::Backend void TraceEnd(const char * label, const char * group) override; void TraceInstant(const char * label, const char * group) override; void TraceCounter(const char * label) override; - void TraceMetric(const char * label, int32_t val) override; void LogMessageSend(MessageSendInfo &) override; void LogMessageReceived(MessageReceivedInfo &) override; void LogNodeLookup(NodeLookupInfo &) override; void LogNodeDiscovered(NodeDiscoveredInfo &) override; void LogNodeDiscoveryFailed(NodeDiscoveryFailedInfo &) override; + void LogMetricEvent(const MetricEvent &) override; void Close() override { CloseFile(); } private: diff --git a/src/tracing/log_declares.h b/src/tracing/log_declares.h index 5e502d0c93af6c..72ebbce7c18011 100644 --- a/src/tracing/log_declares.h +++ b/src/tracing/log_declares.h @@ -27,6 +27,7 @@ struct MessageReceivedInfo; struct NodeLookupInfo; struct NodeDiscoveredInfo; struct NodeDiscoveryFailedInfo; +class MetricEvent; } // namespace Tracing } // namespace chip diff --git a/src/tracing/macros.h b/src/tracing/macros.h index 0643a466c2a77d..1a9b4569e2a35b 100644 --- a/src/tracing/macros.h +++ b/src/tracing/macros.h @@ -30,10 +30,6 @@ // Tracing macro to trace monotonically increasing counter values. // MATTER_TRACE_COUNTER(label) -// Tracing macro to represent historical metric data i.e the data points which represent different -// values at different point of time. -// MATTER_TRACE_METRIC(label, value) - #include #include #include @@ -87,7 +83,6 @@ #define MATTER_TRACE_INSTANT(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) #define MATTER_TRACE_SCOPE(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) #define MATTER_TRACE_COUNTER(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) -#define MATTER_TRACE_METRIC(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) #define MATTER_LOG_MESSAGE_SEND(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) #define MATTER_LOG_MESSAGE_RECEIVED(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) diff --git a/src/tracing/metric_event.h b/src/tracing/metric_event.h new file mode 100644 index 00000000000000..7bb5d8b5b81b51 --- /dev/null +++ b/src/tracing/metric_event.h @@ -0,0 +1,189 @@ +/* + * Copyright (c) 2024 Project CHIP Authors + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include +#include +#include +#include + +namespace chip { +namespace Tracing { + +/** + * Define a metric that can be logged. A metric consists of a key and an optional value pair. + * The value is currently limited to simple scalar values. + * + * Additionally a metric is tagged as either an instant event or marked with a begin/end + * for the event. When the latter is used, a duration can be associated between the two events. + */ +class MetricEvent +{ +public: + MetricEvent(const MetricEvent &) = default; + MetricEvent(MetricEvent &&) = default; + MetricEvent & operator=(const MetricEvent &) = default; + MetricEvent & operator=(MetricEvent &&) = default; + + // This specifies the different categories of metric events that can created. In addition to + // emitting an event, events paired with a kBeginEvent and kEndEvent can be used to track + // duration for the event. A kInstantEvent represents a one shot event. + enum class Type + { + // This specifies an event marked to track the Begin of an operation + kBeginEvent, + + // This specifies an event marked to track the End of an operation + kEndEvent, + + // This specifies a one shot event + kInstantEvent + }; + + // This defines the different types of values that can stored when a metric is emitted + struct Value + { + Value(const Value &) = default; + Value(Value &&) = default; + Value & operator=(const Value &) = default; + Value & operator=(Value &&) = default; + + enum class Type : uint8_t + { + kUndefined, // Value is not valid + kInt32, // int32_t + kUInt32, // uint32_t + kChipErrorCode // chip::ChipError + }; + + union Store + { + int32_t int32_value; + uint32_t uint32_value; + + Store() {} + + Store(int32_t v) : int32_value(v) {} + + Store(uint32_t v) : uint32_value(v) {} + }; + + Store store; + Type type; + + Value() : type(Type::kUndefined) {} + + Value(uint32_t value) : store(value), type(Type::kUInt32) {} + + Value(int32_t value) : store(value), type(Type::kInt32) {} + + Value(const ChipError & err) : store(err.AsInteger()), type(Type::kChipErrorCode) {} + }; + + MetricEvent(Type type, MetricKey key) : mType(type), mKey(key) {} + + MetricEvent(Type type, MetricKey key, int32_t value) : mType(type), mKey(key), mValue(value) {} + + MetricEvent(Type type, MetricKey key, uint32_t value) : mType(type), mKey(key), mValue(value) {} + + MetricEvent(Type type, MetricKey key, const ChipError & error) : mType(type), mKey(key), mValue(error) {} + + MetricEvent(Type type, MetricKey key, Value value) : mType(type), mKey(key), mValue(value) {} + + MetricEvent(Type type, MetricKey key, int8_t value) : MetricEvent(type, key, int32_t(value)) {} + + MetricEvent(Type type, MetricKey key, uint8_t value) : MetricEvent(type, key, uint32_t(value)) {} + + MetricEvent(Type type, MetricKey key, int16_t value) : MetricEvent(type, key, int32_t(value)) {} + + MetricEvent(Type type, MetricKey key, uint16_t value) : MetricEvent(type, key, uint32_t(value)) {} + + Type type() const { return mType; } + + MetricKey key() const { return mKey; } + + Value::Type ValueType() const { return mValue.type; } + + uint32_t ValueUInt32() const + { + VerifyOrDie(mValue.type == Value::Type::kUInt32); + return mValue.store.uint32_value; + } + + int32_t ValueInt32() const + { + VerifyOrDie(mValue.type == Value::Type::kInt32); + return mValue.store.int32_value; + } + + uint32_t ValueErrorCode() const + { + VerifyOrDie(mValue.type == Value::Type::kChipErrorCode); + return mValue.store.uint32_value; + } + +private: + Type mType; + MetricKey mKey; + Value mValue; +}; + +namespace ErrorHandling { + +/** + * Utility to emit an instant metric if the error is not a success. + */ +inline bool LogMetricIfError(MetricKey metricKey, const ::chip::ChipError & err) +{ + bool success = ::chip::ChipError::IsSuccess(err); + if (!success) + { + MATTER_LOG_METRIC(metricKey, err); + } + return success; +} + +} // namespace ErrorHandling + +/** + * This utility class helps generate a Begin and End metric event within the scope of a block using RAII. + */ +class ScopedMetricEvent +{ +public: + ScopedMetricEvent(const ScopedMetricEvent &) = delete; + ScopedMetricEvent(ScopedMetricEvent &&) = delete; + ScopedMetricEvent & operator=(const ScopedMetricEvent &) = delete; + ScopedMetricEvent & operator=(ScopedMetricEvent &&) = delete; + + ScopedMetricEvent(MetricKey key, ChipError & error) : mKey(key), mError(error) + { + MATTER_LOG_METRIC_BEGIN(mKey); + IgnoreUnusedVariable(mKey); + IgnoreUnusedVariable(mError); + } + + ~ScopedMetricEvent() { MATTER_LOG_METRIC_END(mKey, mError); } + +private: + MetricKey mKey; + ChipError & mError; +}; + +} // namespace Tracing +} // namespace chip diff --git a/src/tracing/metric_keys.h b/src/tracing/metric_keys.h new file mode 100644 index 00000000000000..f52b2ab3244776 --- /dev/null +++ b/src/tracing/metric_keys.h @@ -0,0 +1,44 @@ +/* + * Copyright (c) 2024 Project CHIP Authors + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include + +namespace chip { +namespace Tracing { + +/** + * Defines the key type use to identity a specific metric + */ +typedef const char * MetricKey; + +/** + * List of supported metric keys + */ +constexpr MetricKey kMetricDiscoveryOverBLE = "disc-over-ble"; +constexpr MetricKey kMetricDiscoveryOnNetwork = "disc-on-nw"; +constexpr MetricKey kMetricPASESession = "pase-session"; +constexpr MetricKey kMetricPASESessionPair = "pase-session-pair"; +constexpr MetricKey kMetricPASESessionBLE = "pase-session-ble"; +constexpr MetricKey kMetricAttestationResult = "attestation-result"; +constexpr MetricKey kMetricAttestationOverridden = "attestation-overridden"; +constexpr MetricKey kMetricCASESession = "case-session"; +constexpr MetricKey kMetricCASESessionEstState = "case-conn-est"; +constexpr MetricKey kMetricWiFiRSSI = "wifi_rssi"; + +} // namespace Tracing +} // namespace chip diff --git a/src/tracing/metric_macros.h b/src/tracing/metric_macros.h new file mode 100644 index 00000000000000..4ff85f353701b3 --- /dev/null +++ b/src/tracing/metric_macros.h @@ -0,0 +1,243 @@ +/* + * + * Copyright (c) 2024 Project CHIP Authors + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#pragma once + +#include +#include +#include + +#define __LOG_METRIC_CONCAT_IMPL(a, b) a##b +#define __LOG_METRIC_MACRO_CONCAT(a, b) __LOG_METRIC_CONCAT_IMPL(a, b) + +#if MATTER_TRACING_ENABLED + +/** + * @def SuccessOrExitWithMetric(kMetriKey, error) + * + * @brief + * This checks for the specified error, which is expected to + * commonly be successful (CHIP_NO_ERROR), and branches to + * the local label 'exit' if the error is not success. + * If error is not a success, a metric with key kMetriKey is emitted with + * the error code as the value of the metric. + * + * Example Usage: + * + * @code + * CHIP_ERROR TryHard() + * { + * CHIP_ERROR err; + * + * err = TrySomething(); + * SuccessOrExitWithMetric(kMetricKey, err); + * + * err = TrySomethingElse(); + * SuccessOrExitWithMetric(kMetricKey, err); + * + * exit: + * return err; + * } + * @endcode + * + * @param[in] kMetricKey Metric key for the metric event to be emitted + * if the condition evaluates to false. The value + * for the metric is result of the expression aStatus. + * @param[in] error A ChipError object to be evaluated against success (CHIP_NO_ERROR). + * + */ +#define SuccessOrExitWithMetric(kMetricKey, error) \ + nlEXPECT(::chip::Tracing::ErrorHandling::LogMetricIfError((kMetricKey), (error)), exit) + +/** + * @def VerifyOrExitWithMetric(kMetricKey, aCondition, anAction) + * + * @brief + * This checks for the specified condition, which is expected to + * commonly be true, and both executes @a anAction and branches to + * the local label 'exit' if the condition is false. If the condition + * is false a metric event with the specified key is emitted with value + * set to the result of the expression anAction. + * + * Example Usage: + * + * @code + * CHIP_ERROR MakeBuffer(const uint8_t *& buf) + * { + * CHIP_ERROR err = CHIP_NO_ERROR; + * + * buf = (uint8_t *)malloc(1024); + * VerifyOrExitWithMetric(kMetricKey, buf != NULL, err = CHIP_ERROR_NO_MEMORY); + * + * memset(buf, 0, 1024); + * + * exit: + * return err; + * } + * @endcode + * + * @param[in] kMetricKey Metric key for the metric event to be emitted + * if the aCondition evaluates to false. The value + * for the metric is result of the expression anAction. + * @param[in] aCondition A Boolean expression to be evaluated. + * @param[in] anAction An expression or block to execute when the + * assertion fails. + */ +#define VerifyOrExitWithMetric(kMetricKey, aCondition, anAction) \ + nlEXPECT_ACTION(aCondition, exit, MATTER_LOG_METRIC((kMetricKey), (anAction))) + +/* + * Utility Macros to support optional arguments for MATTER_LOG_METRIC_XYZ macros + */ + +// Utility to always return the 4th argument from macro parameters +#define __GET_4TH_ARG(_a1, _a2, _a3, _a4, ...) _a4 + +// Utility macro to select the macro with the correct signature based on the invoked MATTER_LOG_METRIC_XYZ macro +#define __SELECT_MACRO_FOR_EVENT_METRIC(...) \ + __GET_4TH_ARG(__VA_ARGS__, __MATTER_LOG_METRIC_3ARGS, __MATTER_LOG_METRIC_2ARGS, __MATTER_LOG_METRIC_1ARGS, ) + +// Wrapper to capture all arguments and invoke the real wrapper for logging metrics +#define __MATTER_LOG_METRIC(...) __SELECT_MACRO_FOR_EVENT_METRIC(__VA_ARGS__)(__VA_ARGS__) + +// Wrapper macro that accepts metric key and logs and instant event +#define __MATTER_LOG_METRIC_1ARGS(key) \ + do \ + { \ + using Type = chip::Tracing::MetricEvent::Type; \ + ::chip::Tracing::MetricEvent _metric_event(Type::kInstantEvent, key); \ + ::chip::Tracing::Internal::LogMetricEvent(_metric_event); \ + } while (false) + +// Wrapper macro that accepts metric type and key and logs an event corresponding to the type +#define __MATTER_LOG_METRIC_2ARGS(type, key) \ + do \ + { \ + ::chip::Tracing::MetricEvent _metric_event(type, key); \ + ::chip::Tracing::Internal::LogMetricEvent(_metric_event); \ + } while (false) + +// Wrapper macro that accepts metric type, key and value and logs the corresponding event +#define __MATTER_LOG_METRIC_3ARGS(type, key, value) \ + do \ + { \ + ::chip::Tracing::MetricEvent _metric_event(type, key, value); \ + ::chip::Tracing::Internal::LogMetricEvent(_metric_event); \ + } while (false) + +//////////////////////// +// Metric logging macros +//////////////////////// + +/** + * @def MATTER_LOG_METRIC + * + * @brief + * When tracing is enabled, this macro generates a metric event and logs it to the tracing backend. + * + * Example usage: + * @code + * MATTER_LOG_METRIC(chip::Tracing::kMetricPASESession, err); + * @endcode + * The above example generates an instant metric event with key kMetricPASESession. + * The metric also holds the 32 bit value corresponding to the ChipError object 'err'. + * + * @param[in] key The key representing the metric name/event. + * + * @param[in] value An optional value for the metric. This value corresponds to one of the values supported + * in MetricEvent::Value + */ +#define MATTER_LOG_METRIC(key, ...) __MATTER_LOG_METRIC(chip::Tracing::MetricEvent::Type::kInstantEvent, key, ##__VA_ARGS__) + +/** + * @def MATTER_LOG_METRIC_BEGIN + * + * @brief + * Generate a metric with the Begin Type + * + * Example usage: + * @code + * MATTER_LOG_METRIC_BEGIN(chip::Tracing::kMetricPASESession); + * @endcode + * The above example generates a Begin metric event with key kMetricPASESession. + * + * @param[in] key The key representing the metric name/event. + */ +#define MATTER_LOG_METRIC_BEGIN(key) __MATTER_LOG_METRIC(chip::Tracing::MetricEvent::Type::kBeginEvent, key) + +/** + * @def MATTER_LOG_METRIC_END + * + * @brief + * Generate a metric with the End Type + * + * Example usage: + * @code + * MATTER_LOG_METRIC_END(chip::Tracing::kMetricPASESession); + * @endcode + * The above example generates an End metric event with key kMetricPASESession. + * + * @param[in] key The key representing the metric name/event. + * + * @param[in] value An optional value for the metric. This value corresponds to one of the values supported + * in MetricEvent::Value + */ +#define MATTER_LOG_METRIC_END(key, ...) __MATTER_LOG_METRIC(chip::Tracing::MetricEvent::Type::kEndEvent, key, ##__VA_ARGS__) + +/** + * @def MATTER_LOG_METRIC_SCOPE + * + * @brief + * Generate a scoped metric tracking Begin and End within a given scope. + * + * Example usage: + * @code + * MATTER_LOG_METRIC_SCOPE(chip::Tracing::kMetricPASESession); + * @endcode + * The above example generates an Begin and the End metric using RAII. + * + * @param[in] key The key representing the metric name/event. + * @param[in] error Reference to a ChipError object that is used as the value of the End event. + */ +#define MATTER_LOG_METRIC_SCOPE(key, error) \ + ::chip::Tracing::ScopedMetricEvent __LOG_METRIC_MACRO_CONCAT(_metric_scope, __COUNTER__)(key, error) + +#else // Tracing is disabled + +//////////////////////////////////////////////////////////////////////////////////////////////////////////////// +// Remap Success, Return, and Verify macros to the ones without metrics +//////////////////////////////////////////////////////////////////////////////////////////////////////////////// + +#define SuccessOrExitWithMetric(kMetricKey, aStatus) SuccessOrExit(aStatus) + +#define VerifyOrExitWithMetric(kMetricKey, aCondition, anAction) VerifyOrExit(aCondition, anAction) + +//////////////////////////////////////////////////////////////////////////////////////////////////////////////// +// Map all MATTER_LOG_METRIC_XYZ macros to noops +//////////////////////////////////////////////////////////////////////////////////////////////////////////////// + +#define __MATTER_LOG_METRIC_DISABLE(...) \ + do \ + { \ + } while (false) + +#define MATTER_LOG_METRIC(...) __MATTER_LOG_METRIC_DISABLE(__VA_ARGS__) +#define MATTER_LOG_METRIC_BEGIN(...) __MATTER_LOG_METRIC_DISABLE(__VA_ARGS__) +#define MATTER_LOG_METRIC_END(...) __MATTER_LOG_METRIC_DISABLE(__VA_ARGS__) +#define MATTER_LOG_METRIC_SCOPE(...) __MATTER_LOG_METRIC_DISABLE(__VA_ARGS__) + +#endif // MATTER_TRACING_ENABLED diff --git a/src/tracing/multiplexed/include/matter/tracing/macros_impl.h b/src/tracing/multiplexed/include/matter/tracing/macros_impl.h index eda5f2ed5142a4..8b3e728289dc1d 100644 --- a/src/tracing/multiplexed/include/matter/tracing/macros_impl.h +++ b/src/tracing/multiplexed/include/matter/tracing/macros_impl.h @@ -29,7 +29,6 @@ #define MATTER_TRACE_END(label, group) ::chip::Tracing::Internal::End(label, group) #define MATTER_TRACE_INSTANT(label, group) ::chip::Tracing::Internal::Instant(label, group) #define MATTER_TRACE_COUNTER(label) ::chip::Tracing::Internal::Counter(label) -#define MATTER_TRACE_METRIC(label, value) ::chip::Tracing::Internal::Metric(label, value) namespace chip { namespace Tracing { diff --git a/src/tracing/none/include/matter/tracing/macros_impl.h b/src/tracing/none/include/matter/tracing/macros_impl.h index 1fc940683d75e2..3119dce2a2b49f 100644 --- a/src/tracing/none/include/matter/tracing/macros_impl.h +++ b/src/tracing/none/include/matter/tracing/macros_impl.h @@ -32,4 +32,3 @@ #define MATTER_TRACE_INSTANT(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) #define MATTER_TRACE_SCOPE(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) #define MATTER_TRACE_COUNTER(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) -#define MATTER_TRACE_METRIC(...) _MATTER_TRACE_DISABLE(__VA_ARGS__) diff --git a/src/tracing/perfetto/include/matter/tracing/macros_impl.h b/src/tracing/perfetto/include/matter/tracing/macros_impl.h index 559e877db1fe11..9b05d2f3539a45 100644 --- a/src/tracing/perfetto/include/matter/tracing/macros_impl.h +++ b/src/tracing/perfetto/include/matter/tracing/macros_impl.h @@ -37,5 +37,3 @@ PERFETTO_DEFINE_CATEGORIES(perfetto::Category("Matter").SetDescription("Matter t static int count##_label = 0; \ TRACE_COUNTER("Matter", label, ++count##_label); \ } while (0) - -#define MATTER_TRACE_METRIC(label, value) TRACE_COUNTER("Matter", label, value) diff --git a/src/tracing/perfetto/perfetto_tracing.cpp b/src/tracing/perfetto/perfetto_tracing.cpp index b68ec33d33101d..f9b00cc7ad96d3 100644 --- a/src/tracing/perfetto/perfetto_tracing.cpp +++ b/src/tracing/perfetto/perfetto_tracing.cpp @@ -16,6 +16,7 @@ * limitations under the License. */ +#include #include #include @@ -126,6 +127,29 @@ void PerfettoBackend::LogNodeDiscoveryFailed(NodeDiscoveryFailedInfo & info) ); } +void PerfettoBackend::LogMetricEvent(const MetricEvent & event) +{ + using ValueType = MetricEvent::Value::Type; + switch (event.ValueType()) + { + case ValueType::kInt32: + TRACE_EVENT_INSTANT("Matter", event.key(), "value", event.ValueInt32()); + break; + case ValueType::kUInt32: + TRACE_EVENT_INSTANT("Matter", event.key(), "value", event.ValueUInt32()); + break; + case ValueType::kChipErrorCode: + TRACE_EVENT_INSTANT("Matter", event.key(), "error", event.ValueErrorCode()); + break; + case ValueType::kUndefined: + TRACE_EVENT_INSTANT("Matter", event.key()); + break; + default: + TRACE_EVENT_INSTANT("Matter", event.key(), "type", "UNKNOWN"); + break; + } +} + } // namespace Perfetto } // namespace Tracing } // namespace chip diff --git a/src/tracing/perfetto/perfetto_tracing.h b/src/tracing/perfetto/perfetto_tracing.h index 901165e35a548d..05fee4b49934de 100644 --- a/src/tracing/perfetto/perfetto_tracing.h +++ b/src/tracing/perfetto/perfetto_tracing.h @@ -44,6 +44,7 @@ class PerfettoBackend : public ::chip::Tracing::Backend void LogNodeLookup(NodeLookupInfo &) override; void LogNodeDiscovered(NodeDiscoveredInfo &) override; void LogNodeDiscoveryFailed(NodeDiscoveryFailedInfo &) override; + void LogMetricEvent(const MetricEvent &) override; }; } // namespace Perfetto diff --git a/src/tracing/registry.cpp b/src/tracing/registry.cpp index ee46b542e7f5f2..a4fcdbe81c650f 100644 --- a/src/tracing/registry.cpp +++ b/src/tracing/registry.cpp @@ -84,14 +84,6 @@ void Counter(const char * label) } } -void Metric(const char * label, int32_t value) -{ - for (auto & backend : gTracingBackends) - { - backend.TraceMetric(label, value); - } -} - void LogMessageSend(::chip::Tracing::MessageSendInfo & info) { for (auto & backend : gTracingBackends) @@ -132,6 +124,14 @@ void LogNodeDiscoveryFailed(::chip::Tracing::NodeDiscoveryFailedInfo & info) } } +void LogMetricEvent(const ::chip::Tracing::MetricEvent & event) +{ + for (auto & backend : gTracingBackends) + { + backend.LogMetricEvent(event); + } +} + } // namespace Internal #endif // MATTTER_TRACING_ENABLED diff --git a/src/tracing/registry.h b/src/tracing/registry.h index 5f3b3c1a6cea84..7d14522c56e708 100644 --- a/src/tracing/registry.h +++ b/src/tracing/registry.h @@ -77,13 +77,13 @@ void Begin(const char * label, const char * group); void End(const char * label, const char * group); void Instant(const char * label, const char * group); void Counter(const char * label); -void Metric(const char * label, int32_t value); void LogMessageSend(::chip::Tracing::MessageSendInfo & info); void LogMessageReceived(::chip::Tracing::MessageReceivedInfo & info); void LogNodeLookup(::chip::Tracing::NodeLookupInfo & info); void LogNodeDiscovered(::chip::Tracing::NodeDiscoveredInfo & info); void LogNodeDiscoveryFailed(::chip::Tracing::NodeDiscoveryFailedInfo & info); +void LogMetricEvent(const ::chip::Tracing::MetricEvent & event); } // namespace Internal diff --git a/src/tracing/tracing_args.gni b/src/tracing/tracing_args.gni index d3741b5eba5f10..d6ddb1fd2e99b8 100644 --- a/src/tracing/tracing_args.gni +++ b/src/tracing/tracing_args.gni @@ -23,7 +23,8 @@ declare_args() { # # Additionally, if tracing is enabled, the main() function has to add # backends explicitly - matter_enable_tracing_support = current_os == "android" + matter_enable_tracing_support = + current_os == "android" || chip_device_platform == "darwin" # Defines the trace backend. Current matter tracing splits the logic # into two parts: @@ -46,6 +47,8 @@ declare_args() { # if (current_os == "linux" || current_os == "android") { matter_trace_config = "${chip_root}/src/tracing/perfetto:perfetto_tracing" + } else if (chip_device_platform == "darwin") { + matter_trace_config = "${chip_root}/src/tracing/darwin:darwin_tracing" } else { matter_trace_config = "${chip_root}/src/tracing/none" }