Added fabric, secure channel and cluster specfic traces for better t…

…racing. (#31238) * Added few secure channel CASE related traces * Added PASE related traces * Added some fabric related traces * Added cluster specific traces * Addressed review comments * Restlyed the code * Update src/credentials/FabricTable.cpp Co-authored-by: Shubham Patil <[email protected]> --------- Co-authored-by: Shubham Patil <[email protected]>
project-chip · Feb 21, 2024 · 8aada7e · 8aada7e
1 parent b2197b2
commit 8aada7e
Show file tree

Hide file tree

Showing 19 changed files with 114 additions and 9 deletions.
diff --git a/src/app/clusters/administrator-commissioning-server/administrator-commissioning-server.cpp b/src/app/clusters/administrator-commissioning-server/administrator-commissioning-server.cpp
@@ -35,6 +35,7 @@
 #include <protocols/interaction_model/Constants.h>
 #include <setup_payload/SetupPayload.h>
 #include <system/SystemClock.h>
+#include <tracing/macros.h>
 
 using namespace chip;
 using namespace chip::app;
@@ -82,6 +83,7 @@ bool emberAfAdministratorCommissioningClusterOpenCommissioningWindowCallback(
     app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
     const Commands::OpenCommissioningWindow::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("OpenCommissioningWindow", "AdministratorCommissioning");
     auto commissioningTimeout = System::Clock::Seconds16(commandData.commissioningTimeout);
     auto & pakeVerifier       = commandData.PAKEPasscodeVerifier;
     auto & discriminator      = commandData.discriminator;
@@ -141,6 +143,7 @@ bool emberAfAdministratorCommissioningClusterOpenBasicCommissioningWindowCallbac
     app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
     const Commands::OpenBasicCommissioningWindow::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("OpenBasicCommissioningWindow", "AdministratorCommissioning");
     auto commissioningTimeout = System::Clock::Seconds16(commandData.commissioningTimeout);
 
     Optional<StatusCode> status           = Optional<StatusCode>::Missing();
@@ -187,6 +190,7 @@ bool emberAfAdministratorCommissioningClusterRevokeCommissioningCallback(
     app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
     const Commands::RevokeCommissioning::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("RevokeCommissioning", "AdministratorCommissioning");
     ChipLogProgress(Zcl, "Received command to close commissioning window");
 
     Server::GetInstance().GetFailSafeContext().ForceFailSafeTimerExpiry();

diff --git a/src/app/clusters/basic-information/basic-information.cpp b/src/app/clusters/basic-information/basic-information.cpp
@@ -33,6 +33,7 @@
 
 #include <cstddef>
 #include <cstring>
+#include <tracing/macros.h>
 
 using namespace chip;
 using namespace chip::app;
@@ -410,6 +411,7 @@ class PlatformMgrDelegate : public DeviceLayer::PlatformManagerDelegate
 {
     void OnStartUp(uint32_t softwareVersion) override
     {
+        MATTER_TRACE_INSTANT("OnStartUp", "BasicInfo");
         // The StartUp event SHALL be emitted by a Node after completing a boot or reboot process
         ChipLogDetail(Zcl, "Emitting StartUp event");
 
@@ -429,6 +431,7 @@ class PlatformMgrDelegate : public DeviceLayer::PlatformManagerDelegate
 
     void OnShutDown() override
     {
+        MATTER_TRACE_INSTANT("OnShutDown", "BasicInfo");
         // The ShutDown event SHOULD be emitted on a best-effort basis by a Node prior to any orderly shutdown sequence.
         ChipLogDetail(Zcl, "Emitting ShutDown event");
 

diff --git a/...sters/bridged-device-basic-information-server/bridged-device-basic-information-server.cpp b/...sters/bridged-device-basic-information-server/bridged-device-basic-information-server.cpp
@@ -26,6 +26,7 @@
 #include <app/util/basic-types.h>
 #include <lib/core/CHIPError.h>
 #include <lib/support/logging/CHIPLogging.h>
+#include <tracing/macros.h>
 
 using namespace chip;
 using namespace chip::app;
@@ -36,6 +37,7 @@ namespace {
 
 void ReachableChanged(EndpointId endpointId)
 {
+    MATTER_TRACE_INSTANT("ReachableChanged", "BridgeBasicInfo");
     bool reachable = false;
     if (EMBER_ZCL_STATUS_SUCCESS != Attributes::Reachable::Get(endpointId, &reachable))
     {

diff --git a/src/app/clusters/color-control-server/color-control-server.cpp b/src/app/clusters/color-control-server/color-control-server.cpp
@@ -24,6 +24,7 @@
 #include <app/util/config.h>
 #include <platform/CHIPDeviceLayer.h>
 #include <platform/PlatformManager.h>
+#include <tracing/macros.h>
 
 #ifdef EMBER_AF_PLUGIN_SCENES_MANAGEMENT
 #include <app/clusters/scenes-server/scenes-server.h>
@@ -1354,6 +1355,7 @@ bool ColorControlServer::moveHueCommand(app::CommandHandler * commandObj, const
                                         HueMoveMode moveMode, uint16_t rate, uint8_t optionsMask, uint8_t optionsOverride,
                                         bool isEnhanced)
 {
+    MATTER_TRACE_SCOPE("moveHue", "ColorControl");
     EndpointId endpoint                               = commandPath.mEndpointId;
     Status status                                     = Status::Success;
     ColorHueTransitionState * colorHueTransitionState = getColorHueTransitionState(endpoint);
@@ -1459,6 +1461,7 @@ bool ColorControlServer::moveToHueCommand(app::CommandHandler * commandObj, cons
                                           uint16_t hue, HueDirection moveDirection, uint16_t transitionTime, uint8_t optionsMask,
                                           uint8_t optionsOverride, bool isEnhanced)
 {
+    MATTER_TRACE_SCOPE("moveToHue", "ColorControl");
     EndpointId endpoint = commandPath.mEndpointId;
 
     Status status       = Status::Success;
@@ -1593,6 +1596,7 @@ bool ColorControlServer::moveToHueAndSaturationCommand(app::CommandHandler * com
                                                        uint8_t saturation, uint16_t transitionTime, uint8_t optionsMask,
                                                        uint8_t optionsOverride, bool isEnhanced)
 {
+    MATTER_TRACE_SCOPE("moveToHueAndSaturation", "ColorControl");
     // limit checking:  hue and saturation are 0..254.  Spec dictates we ignore
     // this and report a constraint error.
     if ((!isEnhanced && hue > MAX_HUE_VALUE) || saturation > MAX_SATURATION_VALUE)
@@ -1632,6 +1636,7 @@ bool ColorControlServer::stepHueCommand(app::CommandHandler * commandObj, const
                                         HueStepMode stepMode, uint16_t stepSize, uint16_t transitionTime, uint8_t optionsMask,
                                         uint8_t optionsOverride, bool isEnhanced)
 {
+    MATTER_TRACE_SCOPE("stepHue", "ColorControl");
     EndpointId endpoint = commandPath.mEndpointId;
 
     Status status = Status::Success;
@@ -1715,6 +1720,7 @@ bool ColorControlServer::stepHueCommand(app::CommandHandler * commandObj, const
 bool ColorControlServer::moveSaturationCommand(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                const Commands::MoveSaturation::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("moveSaturation", "ColorControl");
     auto & moveMode        = commandData.moveMode;
     auto & rate            = commandData.rate;
     auto & optionsMask     = commandData.optionsMask;
@@ -1798,6 +1804,7 @@ bool ColorControlServer::moveSaturationCommand(app::CommandHandler * commandObj,
 bool ColorControlServer::moveToSaturationCommand(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                  const Commands::MoveToSaturation::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("moveToSaturation", "ColorControl");
     // limit checking: saturation is 0..254.  Spec dictates we ignore
     // this and report a malformed packet.
     if (commandData.saturation > MAX_SATURATION_VALUE)
@@ -1822,6 +1829,7 @@ bool ColorControlServer::moveToSaturationCommand(app::CommandHandler * commandOb
 bool ColorControlServer::stepSaturationCommand(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                const Commands::StepSaturation::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("stepSaturation", "ColorControl");
     auto stepMode             = commandData.stepMode;
     uint8_t stepSize          = commandData.stepSize;
     uint8_t transitionTime    = commandData.transitionTime;
@@ -1885,6 +1893,7 @@ bool ColorControlServer::stepSaturationCommand(app::CommandHandler * commandObj,
 bool ColorControlServer::colorLoopCommand(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                           const Commands::ColorLoopSet::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("colorLoop", "ColorControl");
     auto updateFlags          = commandData.updateFlags;
     auto action               = commandData.action;
     auto direction            = commandData.direction;
@@ -2010,6 +2019,7 @@ bool ColorControlServer::colorLoopCommand(app::CommandHandler * commandObj, cons
  */
 void ColorControlServer::updateHueSatCommand(EndpointId endpoint)
 {
+    MATTER_TRACE_SCOPE("updateHueSat", "ColorControl");
     ColorHueTransitionState * colorHueTransitionState        = getColorHueTransitionState(endpoint);
     Color16uTransitionState * colorSaturationTransitionState = getSaturationTransitionState(endpoint);
 

diff --git a/src/app/clusters/groups-server/groups-server.cpp b/src/app/clusters/groups-server/groups-server.cpp
@@ -28,6 +28,7 @@
 #include <credentials/GroupDataProvider.h>
 #include <inttypes.h>
 #include <lib/support/CodeUtils.h>
+#include <tracing/macros.h>
 
 #ifdef EMBER_AF_PLUGIN_SCENES_MANAGEMENT
 #include <app/clusters/scenes-server/scenes-server.h>
@@ -141,6 +142,7 @@ void emberAfGroupsClusterServerInitCallback(EndpointId endpointId)
 bool emberAfGroupsClusterAddGroupCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                           const Commands::AddGroup::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("AddGroup", "Groups");
     auto fabricIndex = commandObj->GetAccessingFabricIndex();
     Groups::Commands::AddGroupResponse::Type response;
 
@@ -153,6 +155,7 @@ bool emberAfGroupsClusterAddGroupCallback(app::CommandHandler * commandObj, cons
 bool emberAfGroupsClusterViewGroupCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                            const Commands::ViewGroup::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("ViewGroup", "Groups");
     auto fabricIndex             = commandObj->GetAccessingFabricIndex();
     auto groupId                 = commandData.groupID;
     GroupDataProvider * provider = GetGroupDataProvider();
@@ -255,6 +258,7 @@ struct GroupMembershipResponse
 bool emberAfGroupsClusterGetGroupMembershipCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                     const Commands::GetGroupMembership::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("GetGroupMembership", "Groups");
     auto fabricIndex = commandObj->GetAccessingFabricIndex();
     auto * provider  = GetGroupDataProvider();
     Status status    = Status::Failure;
@@ -284,6 +288,7 @@ bool emberAfGroupsClusterGetGroupMembershipCallback(app::CommandHandler * comman
 bool emberAfGroupsClusterRemoveGroupCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                              const Commands::RemoveGroup::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("RemoveGroup", "Groups");
     auto fabricIndex = commandObj->GetAccessingFabricIndex();
     Groups::Commands::RemoveGroupResponse::Type response;
 
@@ -301,6 +306,7 @@ bool emberAfGroupsClusterRemoveGroupCallback(app::CommandHandler * commandObj, c
 bool emberAfGroupsClusterRemoveAllGroupsCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                  const Commands::RemoveAllGroups::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("RemoveAllGroups", "Groups");
     auto fabricIndex = commandObj->GetAccessingFabricIndex();
     auto * provider  = GetGroupDataProvider();
     Status status    = Status::Failure;
@@ -342,6 +348,7 @@ bool emberAfGroupsClusterAddGroupIfIdentifyingCallback(app::CommandHandler * com
                                                        const app::ConcreteCommandPath & commandPath,
                                                        const Commands::AddGroupIfIdentifying::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("AddGroupIfIdentifying", "Groups");
     auto fabricIndex = commandObj->GetAccessingFabricIndex();
     auto groupId     = commandData.groupID;
     auto groupName   = commandData.groupName;

diff --git a/src/app/clusters/identify-server/identify-server.cpp b/src/app/clusters/identify-server/identify-server.cpp
@@ -31,6 +31,7 @@
 #include <array>
 #include <lib/support/CodeUtils.h>
 #include <platform/CHIPDeviceLayer.h>
+#include <tracing/macros.h>
 
 #if CHIP_DEVICE_LAYER_NONE
 #error "identify requrires a device layer"
@@ -196,6 +197,7 @@ void MatterIdentifyClusterServerAttributeChangedCallback(const app::ConcreteAttr
 bool emberAfIdentifyClusterIdentifyCallback(CommandHandler * commandObj, const ConcreteCommandPath & commandPath,
                                             const Commands::Identify::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("IdentifyCommand", "Identify");
     auto & identifyTime = commandData.identifyTime;
 
     // cmd Identify
@@ -207,6 +209,7 @@ bool emberAfIdentifyClusterIdentifyCallback(CommandHandler * commandObj, const C
 bool emberAfIdentifyClusterTriggerEffectCallback(CommandHandler * commandObj, const ConcreteCommandPath & commandPath,
                                                  const Commands::TriggerEffect::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("TriggerEffect", "Identify");
     auto & effectIdentifier = commandData.effectIdentifier;
     auto & effectVariant    = commandData.effectVariant;
 

diff --git a/src/app/clusters/level-control/level-control.cpp b/src/app/clusters/level-control/level-control.cpp
@@ -33,6 +33,7 @@
 #include <platform/CHIPDeviceConfig.h>
 #include <platform/CHIPDeviceLayer.h>
 #include <platform/PlatformManager.h>
+#include <tracing/macros.h>
 
 #ifdef EMBER_AF_PLUGIN_SCENES_MANAGEMENT
 #include <app/clusters/scenes-server/scenes-server.h>
@@ -577,6 +578,7 @@ static bool shouldExecuteIfOff(EndpointId endpoint, CommandId commandId, chip::O
 bool emberAfLevelControlClusterMoveToLevelCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                    const Commands::MoveToLevel::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("MoveToLevel", "LevelControl");
     commandObj->AddStatus(commandPath, LevelControlServer::MoveToLevel(commandPath.mEndpointId, commandData));
     return true;
 }
@@ -621,6 +623,7 @@ bool emberAfLevelControlClusterMoveToLevelWithOnOffCallback(app::CommandHandler
                                                             const app::ConcreteCommandPath & commandPath,
                                                             const Commands::MoveToLevelWithOnOff::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("MoveToLevelWithOnOff", "LevelControl");
     auto & level           = commandData.level;
     auto & transitionTime  = commandData.transitionTime;
     auto & optionsMask     = commandData.optionsMask;
@@ -650,6 +653,7 @@ bool emberAfLevelControlClusterMoveToLevelWithOnOffCallback(app::CommandHandler
 bool emberAfLevelControlClusterMoveCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                             const Commands::Move::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("Move", "LevelControl");
     auto & moveMode        = commandData.moveMode;
     auto & rate            = commandData.rate;
     auto & optionsMask     = commandData.optionsMask;
@@ -674,6 +678,7 @@ bool emberAfLevelControlClusterMoveCallback(app::CommandHandler * commandObj, co
 bool emberAfLevelControlClusterMoveWithOnOffCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                      const Commands::MoveWithOnOff::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("MoveWithOnOff", "LevelControl");
     auto & moveMode        = commandData.moveMode;
     auto & rate            = commandData.rate;
     auto & optionsMask     = commandData.optionsMask;
@@ -698,6 +703,7 @@ bool emberAfLevelControlClusterMoveWithOnOffCallback(app::CommandHandler * comma
 bool emberAfLevelControlClusterStepCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                             const Commands::Step::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("Step", "LevelControl");
     auto & stepMode        = commandData.stepMode;
     auto & stepSize        = commandData.stepSize;
     auto & transitionTime  = commandData.transitionTime;
@@ -723,6 +729,7 @@ bool emberAfLevelControlClusterStepCallback(app::CommandHandler * commandObj, co
 bool emberAfLevelControlClusterStepWithOnOffCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                      const Commands::StepWithOnOff::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("StepWithOnOff", "LevelControl");
     auto & stepMode        = commandData.stepMode;
     auto & stepSize        = commandData.stepSize;
     auto & transitionTime  = commandData.transitionTime;
@@ -748,6 +755,7 @@ bool emberAfLevelControlClusterStepWithOnOffCallback(app::CommandHandler * comma
 bool emberAfLevelControlClusterStopCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                             const Commands::Stop::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("Stop", "LevelControl");
     auto & optionsMask     = commandData.optionsMask;
     auto & optionsOverride = commandData.optionsOverride;
 
@@ -760,6 +768,7 @@ bool emberAfLevelControlClusterStopCallback(app::CommandHandler * commandObj, co
 bool emberAfLevelControlClusterStopWithOnOffCallback(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath,
                                                      const Commands::StopWithOnOff::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("StopWithOnOff", "LevelControl");
     auto & optionsMask     = commandData.optionsMask;
     auto & optionsOverride = commandData.optionsOverride;
     ChipLogProgress(Zcl, "%s STOP_WITH_ON_OFF", "RX level-control:");

diff --git a/src/app/clusters/low-power-server/low-power-server.cpp b/src/app/clusters/low-power-server/low-power-server.cpp
@@ -31,6 +31,7 @@
 #include <app/util/config.h>
 #include <platform/CHIPDeviceConfig.h>
 #include <protocols/interaction_model/StatusCode.h>
+#include <tracing/macros.h>
 
 using namespace chip;
 using namespace chip::app::Clusters;
@@ -93,6 +94,7 @@ void SetDefaultDelegate(EndpointId endpoint, Delegate * delegate)
 bool emberAfLowPowerClusterSleepCallback(app::CommandHandler * command, const app::ConcreteCommandPath & commandPath,
                                          const Commands::Sleep::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("Sleep", "LowPower");
     using Protocols::InteractionModel::Status;
 
     EndpointId endpoint = commandPath.mEndpointId;

diff --git a/src/app/clusters/mode-base-server/mode-base-server.cpp b/src/app/clusters/mode-base-server/mode-base-server.cpp
@@ -24,6 +24,7 @@
 #include <app/reporting/reporting.h>
 #include <app/util/attribute-storage.h>
 #include <platform/DiagnosticDataProvider.h>
+#include <tracing/macros.h>
 
 using namespace chip;
 using namespace chip::app;
@@ -378,6 +379,7 @@ void Instance::UnregisterThisInstance()
 
 void Instance::HandleChangeToMode(HandlerContext & ctx, const Commands::ChangeToMode::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("ChangeToMode", "ModeBase");
     uint8_t newMode = commandData.newMode;
 
     Commands::ChangeToModeResponse::Type response;

diff --git a/src/app/clusters/mode-select-server/mode-select-server.cpp b/src/app/clusters/mode-select-server/mode-select-server.cpp
@@ -32,6 +32,7 @@
 #include <app/util/util.h>
 #include <lib/support/CodeUtils.h>
 #include <platform/DiagnosticDataProvider.h>
+#include <tracing/macros.h>
 
 #ifdef EMBER_AF_PLUGIN_ON_OFF
 #include <app/clusters/on-off-server/on-off-server.h>
@@ -98,6 +99,7 @@ CHIP_ERROR ModeSelectAttrAccess::Read(const ConcreteReadAttributePath & aPath, A
 bool emberAfModeSelectClusterChangeToModeCallback(CommandHandler * commandHandler, const ConcreteCommandPath & commandPath,
                                                   const ModeSelect::Commands::ChangeToMode::DecodableType & commandData)
 {
+    MATTER_TRACE_SCOPE("ChangeToMode", "ModeSelect");
     ChipLogProgress(Zcl, "ModeSelect: Entering emberAfModeSelectClusterChangeToModeCallback");
     EndpointId endpointId = commandPath.mEndpointId;
     uint8_t newMode       = commandData.newMode;