Make AddStatus generally VerifyOrDie and have centralized logging (#2…

…8634)

* Define a CommandStatus wrapper to handle logging

* Add required methods in CommandHandler to use the new path logic

* Convert a bunch of calls to AddStatus

* Fix test compilation

* Fix addresponse

* Fix unit tests

* Restyle

* Try to reduce flash usage by not duplicating no context strings

* Restyle

* Code review comments

* More code review fixes

* code review update: addstatus in door lock has no error checking

* Move inline function away - attempt to have less code size changes

* Restyle

---------

Co-authored-by: Andrei Litvin <[email protected]>

src/app/CommandHandler.cpp

@@ -272,7 +272,7 @@ Status CommandHandler::ProcessCommandDataIB(CommandDataIB::Parser & aCommandElem
             ChipLogDetail(DataManagement, "No command " ChipLogFormatMEI " in Cluster " ChipLogFormatMEI " on Endpoint 0x%x",
                           ChipLogValueMEI(concretePath.mCommandId), ChipLogValueMEI(concretePath.mClusterId),
                           concretePath.mEndpointId);
-            return AddStatus(concretePath, commandExists) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
+            return FallibleAddStatus(concretePath, commandExists) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
         }
     }
 
@@ -287,18 +287,18 @@ Status CommandHandler::ProcessCommandDataIB(CommandDataIB::Parser & aCommandElem
         {
             if (err != CHIP_ERROR_ACCESS_DENIED)
             {
-                return AddStatus(concretePath, Status::Failure) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
+                return FallibleAddStatus(concretePath, Status::Failure) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
             }
             // TODO: when wildcard invokes are supported, handle them to discard rather than fail with status
-            return AddStatus(concretePath, Status::UnsupportedAccess) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
+            return FallibleAddStatus(concretePath, Status::UnsupportedAccess) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
         }
     }
 
     if (CommandNeedsTimedInvoke(concretePath.mClusterId, concretePath.mCommandId) && !IsTimedInvoke())
     {
         // TODO: when wildcard invokes are supported, discard a
         // wildcard-expanded path instead of returning a status.
-        return AddStatus(concretePath, Status::NeedsTimedInteraction) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
+        return FallibleAddStatus(concretePath, Status::NeedsTimedInteraction) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
     }
 
     if (CommandIsFabricScoped(concretePath.mClusterId, concretePath.mCommandId))
@@ -312,7 +312,7 @@ Status CommandHandler::ProcessCommandDataIB(CommandDataIB::Parser & aCommandElem
         {
             // TODO: when wildcard invokes are supported, discard a
             // wildcard-expanded path instead of returning a status.
-            return AddStatus(concretePath, Status::UnsupportedAccess) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
+            return FallibleAddStatus(concretePath, Status::UnsupportedAccess) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
         }
     }
 
@@ -337,7 +337,7 @@ Status CommandHandler::ProcessCommandDataIB(CommandDataIB::Parser & aCommandElem
 exit:
     if (err != CHIP_NO_ERROR)
     {
-        return AddStatus(concretePath, Status::InvalidCommand) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
+        return FallibleAddStatus(concretePath, Status::InvalidCommand) != CHIP_NO_ERROR ? Status::Failure : Status::Success;
     }
 
     // We have handled the error status above and put the error status in response, now return success status so we can process
@@ -468,31 +468,31 @@ CHIP_ERROR CommandHandler::AddStatusInternal(const ConcreteCommandPath & aComman
     return FinishStatus();
 }
 
-CHIP_ERROR CommandHandler::AddStatus(const ConcreteCommandPath & aCommandPath, const Status aStatus)
+void CommandHandler::AddStatus(const ConcreteCommandPath & aCommandPath, const Protocols::InteractionModel::Status aStatus,
+                               const char * context)
 {
-    return AddStatusInternal(aCommandPath, StatusIB(aStatus));
+
+    VerifyOrDie(FallibleAddStatus(aCommandPath, aStatus, context) == CHIP_NO_ERROR);
 }
 
-void CommandHandler::AddStatusAndLogIfFailure(const ConcreteCommandPath & aCommandPath, const Status aStatus, const char * aMessage)
+CHIP_ERROR CommandHandler::FallibleAddStatus(const ConcreteCommandPath & path, const Protocols::InteractionModel::Status status,
+                                             const char * context)
 {
-    if (aStatus != Status::Success)
-    {
-        ChipLogError(DataManagement,
-                     "Failed to handle on Endpoint=%u Cluster=" ChipLogFormatMEI " Command=" ChipLogFormatMEI
-                     " with " ChipLogFormatIMStatus ": %s",
-                     aCommandPath.mEndpointId, ChipLogValueMEI(aCommandPath.mClusterId), ChipLogValueMEI(aCommandPath.mCommandId),
-                     ChipLogValueIMStatus(aStatus), aMessage);
-    }
 
-    CHIP_ERROR err = AddStatus(aCommandPath, aStatus);
-    if (err != CHIP_NO_ERROR)
+    if (status != Status::Success)
     {
+        if (context == nullptr)
+        {
+            context = "no additional context";
+        }
+
         ChipLogError(DataManagement,
-                     "Failed to set status on Endpoint=%u Cluster=" ChipLogFormatMEI " Command=" ChipLogFormatMEI
-                     ": %" CHIP_ERROR_FORMAT,
-                     aCommandPath.mEndpointId, ChipLogValueMEI(aCommandPath.mClusterId), ChipLogValueMEI(aCommandPath.mCommandId),
-                     err.Format());
+                     "Endpoint=%u Cluster=" ChipLogFormatMEI " Command=" ChipLogFormatMEI " status " ChipLogFormatIMStatus " (%s)",
+                     path.mEndpointId, ChipLogValueMEI(path.mClusterId), ChipLogValueMEI(path.mCommandId),
+                     ChipLogValueIMStatus(status), context);
     }
+
+    return AddStatusInternal(path, StatusIB(status));
 }
 
 CHIP_ERROR CommandHandler::AddClusterSpecificSuccess(const ConcreteCommandPath & aCommandPath, ClusterStatus aClusterStatus)

src/app/CommandHandler.h

@@ -170,13 +170,20 @@ class CommandHandler : public Messaging::ExchangeDelegate
      */
     void OnInvokeCommandRequest(Messaging::ExchangeContext * ec, const PayloadHeader & payloadHeader,
                                 System::PacketBufferHandle && payload, bool isTimedInvoke);
-    CHIP_ERROR AddStatus(const ConcreteCommandPath & aCommandPath, const Protocols::InteractionModel::Status aStatus);
 
-    // Same as AddStatus, but logs that the command represented by aCommandPath failed with the given
-    // error status and error message, if aStatus is an error. Errors on AddStatus are just logged
-    // (since the caller likely can only log and not further add a status).
-    void AddStatusAndLogIfFailure(const ConcreteCommandPath & aCommandPath, const Protocols::InteractionModel::Status aStatus,
-                                  const char * aMessage);
+    /**
+     * Adds the given command status and returns any failures in adding statuses (e.g. out
+     * of buffer space) to the caller
+     */
+    CHIP_ERROR FallibleAddStatus(const ConcreteCommandPath & aCommandPath, const Protocols::InteractionModel::Status aStatus,
+                                 const char * context = nullptr);
+
+    /**
+     * Adds a status when the caller is unable to handle any failures. Logging is performed
+     * and failure to register the status is checked with VerifyOrDie.
+     */
+    void AddStatus(const ConcreteCommandPath & aCommandPath, const Protocols::InteractionModel::Status aStatus,
+                   const char * context = nullptr);
 
     CHIP_ERROR AddClusterSpecificSuccess(const ConcreteCommandPath & aCommandPath, ClusterStatus aClusterStatus);
 
@@ -238,13 +245,9 @@ class CommandHandler : public Messaging::ExchangeDelegate
     template <typename CommandData>
     void AddResponse(const ConcreteCommandPath & aRequestCommandPath, const CommandData & aData)
     {
-        if (CHIP_NO_ERROR != AddResponseData(aRequestCommandPath, aData))
+        if (AddResponseData(aRequestCommandPath, aData) != CHIP_NO_ERROR)
         {
-            CHIP_ERROR err = AddStatus(aRequestCommandPath, Protocols::InteractionModel::Status::Failure);
-            if (err != CHIP_NO_ERROR)
-            {
-                ChipLogError(DataManagement, "Failed to encode status: %" CHIP_ERROR_FORMAT, err.Format());
-            }
+            AddStatus(aRequestCommandPath, Protocols::InteractionModel::Status::Failure);
         }
     }
 

src/app/CommandResponseHelper.h

@@ -53,7 +53,7 @@ class CommandResponseHelper
 
     CHIP_ERROR Failure(Protocols::InteractionModel::Status aStatus)
     {
-        CHIP_ERROR err = mCommandHandler->AddStatus(mCommandPath, aStatus);
+        CHIP_ERROR err = mCommandHandler->FallibleAddStatus(mCommandPath, aStatus);
         if (err == CHIP_NO_ERROR)
         {
             mSentResponse = true;

src/app/clusters/barrier-control-server/barrier-control-server.cpp

@@ -286,10 +286,7 @@ void emberAfBarrierControlClusterServerTickCallback(EndpointId endpoint)
 
 static void sendDefaultResponse(app::CommandHandler * commandObj, const app::ConcreteCommandPath & commandPath, Status status)
 {
-    if (commandObj->AddStatus(commandPath, status) != CHIP_NO_ERROR)
-    {
-        ChipLogProgress(Zcl, "Failed to send default response");
-    }
+    commandObj->AddStatus(commandPath, status);
 }
 
 bool emberAfBarrierControlClusterBarrierControlGoToPercentCallback(

src/app/clusters/door-lock-server/door-lock-server.cpp

@@ -3314,23 +3314,20 @@ bool DoorLockServer::RemoteOperationEnabled(chip::EndpointId endpointId) const
         mode != OperatingModeEnum::kPrivacy && mode != OperatingModeEnum::kNoRemoteLockUnlock;
 }
 
-CHIP_ERROR DoorLockServer::sendClusterResponse(chip::app::CommandHandler * commandObj,
-                                               const chip::app::ConcreteCommandPath & commandPath, EmberAfStatus status)
+void DoorLockServer::sendClusterResponse(chip::app::CommandHandler * commandObj, const chip::app::ConcreteCommandPath & commandPath,
+                                         EmberAfStatus status)
 {
     VerifyOrDie(nullptr != commandObj);
 
-    auto err             = CHIP_NO_ERROR;
     auto statusAsInteger = to_underlying(status);
     if (statusAsInteger == to_underlying(DlStatus::kOccupied) || statusAsInteger == to_underlying(DlStatus::kDuplicate))
     {
-        err = commandObj->AddClusterSpecificFailure(commandPath, static_cast<chip::ClusterStatus>(status));
+        VerifyOrDie(commandObj->AddClusterSpecificFailure(commandPath, static_cast<chip::ClusterStatus>(status)) == CHIP_NO_ERROR);
     }
     else
     {
-        err = commandObj->AddStatus(commandPath, ToInteractionModelStatus(status));
+        commandObj->AddStatus(commandPath, ToInteractionModelStatus(status));
     }
-
-    return err;
 }
 
 EmberAfDoorLockEndpointContext * DoorLockServer::getContext(chip::EndpointId endpointId)

src/app/clusters/door-lock-server/door-lock-server.h

@@ -422,8 +422,8 @@ class DoorLockServer
 
     bool engageLockout(chip::EndpointId endpointId);
 
-    static CHIP_ERROR sendClusterResponse(chip::app::CommandHandler * commandObj,
-                                          const chip::app::ConcreteCommandPath & commandPath, EmberAfStatus status);
+    static void sendClusterResponse(chip::app::CommandHandler * commandObj, const chip::app::ConcreteCommandPath & commandPath,
+                                    EmberAfStatus status);
 
     /**
      * @brief Common handler for LockDoor, UnlockDoor, UnlockWithTimeout commands

src/app/clusters/general-commissioning-server/general-commissioning-server.cpp

@@ -50,11 +50,7 @@ using Transport::Session;
     {                                                                                                                              \
         if (!::chip::ChipError::IsSuccess(expr))                                                                                   \
         {                                                                                                                          \
-            CHIP_ERROR statusErr = commandObj->AddStatus(commandPath, Protocols::InteractionModel::Status::code);                  \
-            if (statusErr != CHIP_NO_ERROR)                                                                                        \
-            {                                                                                                                      \
-                ChipLogError(Zcl, "%s: %" CHIP_ERROR_FORMAT, #expr, statusErr.Format());                                           \
-            }                                                                                                                      \
+            commandObj->AddStatus(commandPath, Protocols::InteractionModel::Status::code, #expr);                                  \
             return true;                                                                                                           \
         }                                                                                                                          \
     } while (false)

src/app/clusters/group-key-mgmt-server/group-key-mgmt-server.cpp

@@ -414,13 +414,13 @@ bool GetProviderAndFabric(chip::app::CommandHandler * commandObj, const chip::ap
 
     if (nullptr == provider)
     {
-        commandObj->AddStatusAndLogIfFailure(commandPath, Status::Failure, "Internal consistency error on provider!");
+        commandObj->AddStatus(commandPath, Status::Failure, "Internal consistency error on provider!");
         return false;
     }
 
     if (nullptr == fabric)
     {
-        commandObj->AddStatusAndLogIfFailure(commandPath, Status::Failure, "Internal consistency error on access fabric!");
+        commandObj->AddStatus(commandPath, Status::Failure, "Internal consistency error on access fabric!");
         return false;
     }
 
@@ -460,7 +460,7 @@ bool emberAfGroupKeyManagementClusterKeySetWriteCallback(
     Status status = ValidateKeySetWriteArguments(commandData);
     if (status != Status::Success)
     {
-        commandObj->AddStatusAndLogIfFailure(commandPath, status, "Failure to validate KeySet data dependencies.");
+        commandObj->AddStatus(commandPath, status, "Failure to validate KeySet data dependencies.");
         return true;
     }
 
@@ -470,8 +470,7 @@ bool emberAfGroupKeyManagementClusterKeySetWriteCallback(
         // supported by the server, because it is ... a new value unrecognized
         // by a legacy server, then the server SHALL generate a general
         // constraint error
-        commandObj->AddStatusAndLogIfFailure(commandPath, Status::ConstraintError,
-                                             "Received unknown GroupKeySecurityPolicyEnum value");
+        commandObj->AddStatus(commandPath, Status::ConstraintError, "Received unknown GroupKeySecurityPolicyEnum value");
         return true;
     }
 
@@ -482,8 +481,8 @@ bool emberAfGroupKeyManagementClusterKeySetWriteCallback(
         // any action attempting to set CacheAndSync in the
         // GroupKeySecurityPolicy field SHALL fail with an INVALID_COMMAND
         // error.
-        commandObj->AddStatusAndLogIfFailure(commandPath, Status::InvalidCommand,
-                                             "Received a CacheAndSync GroupKeySecurityPolicyEnum when MCSP not supported");
+        commandObj->AddStatus(commandPath, Status::InvalidCommand,
+                              "Received a CacheAndSync GroupKeySecurityPolicyEnum when MCSP not supported");
         return true;
     }
 
@@ -529,7 +528,7 @@ bool emberAfGroupKeyManagementClusterKeySetWriteCallback(
     err = provider->SetKeySet(fabric->GetFabricIndex(), compressed_fabric_id, keyset);
     if (CHIP_ERROR_INVALID_LIST_LENGTH == err)
     {
-        commandObj->AddStatusAndLogIfFailure(commandPath, Status::ResourceExhausted, "Not enough space left to add a new KeySet");
+        commandObj->AddStatus(commandPath, Status::ResourceExhausted, "Not enough space left to add a new KeySet");
         return true;
     }
 
@@ -565,7 +564,7 @@ bool emberAfGroupKeyManagementClusterKeySetReadCallback(
     if (CHIP_NO_ERROR != provider->GetKeySet(fabricIndex, commandData.groupKeySetID, keyset))
     {
         // KeySet ID not found
-        commandObj->AddStatusAndLogIfFailure(commandPath, Status::NotFound, "Keyset ID not found in KeySetRead");
+        commandObj->AddStatus(commandPath, Status::NotFound, "Keyset ID not found in KeySetRead");
         return true;
     }
 
@@ -629,8 +628,7 @@ bool emberAfGroupKeyManagementClusterKeySetRemoveCallback(
     {
         // SPEC: This command SHALL fail with an INVALID_COMMAND status code back to the initiator if the GroupKeySetID being
         // removed is 0, which is the Key Set associated with the Identity Protection Key (IPK).
-        commandObj->AddStatusAndLogIfFailure(commandPath, Status::InvalidCommand,
-                                             "Attempted to KeySetRemove the identity protection key!");
+        commandObj->AddStatus(commandPath, Status::InvalidCommand, "Attempted to KeySetRemove the identity protection key!");
         return true;
     }
 
@@ -649,7 +647,7 @@ bool emberAfGroupKeyManagementClusterKeySetRemoveCallback(
     }
 
     // Send status response.
-    commandObj->AddStatusAndLogIfFailure(commandPath, status, "KeySetRemove failed");
+    commandObj->AddStatus(commandPath, status, "KeySetRemove failed");
     return true;
 }
 
@@ -701,7 +699,7 @@ bool emberAfGroupKeyManagementClusterKeySetReadAllIndicesCallback(
     auto keysIt             = provider->IterateKeySets(fabricIndex);
     if (nullptr == keysIt)
     {
-        commandObj->AddStatusAndLogIfFailure(commandPath, Status::Failure, "Failed iteration of key set indices!");
+        commandObj->AddStatus(commandPath, Status::Failure, "Failed iteration of key set indices!");
         return true;
     }
 

src/app/clusters/groups-server/groups-server.cpp

@@ -351,11 +351,7 @@ bool emberAfGroupsClusterAddGroupIfIdentifyingCallback(app::CommandHandler * com
         status = GroupAdd(fabricIndex, endpointId, groupId, groupName);
     }
 
-    CHIP_ERROR sendErr = commandObj->AddStatus(commandPath, status);
-    if (CHIP_NO_ERROR != sendErr)
-    {
-        ChipLogDetail(Zcl, "Groups: failed to send %s: %" CHIP_ERROR_FORMAT, "status_response", sendErr.Format());
-    }
+    commandObj->AddStatus(commandPath, status);
     return true;
 }
 

src/app/clusters/window-covering-server/window-covering-server.cpp

@@ -771,7 +771,8 @@ bool emberAfWindowCoveringClusterStopMotionCallback(app::CommandHandler * comman
         }
     }
 
-    return CHIP_NO_ERROR == commandObj->AddStatus(commandPath, Status::Success);
+    commandObj->AddStatus(commandPath, Status::Success);
+    return true;
 }
 
 /**

src/app/tests/TestCommandInteraction.cpp

@@ -1095,9 +1095,8 @@ void TestCommandInteraction::TestCommandHandlerCommandEncodeExternalFailure(nlTe
 
     err = commandHandler.AddResponseData(ConcreteCommandPath(path.mEndpointId, path.mClusterId, path.mCommandId), BadFields());
     NL_TEST_ASSERT(apSuite, err != CHIP_NO_ERROR);
-    err = commandHandler.AddStatus(ConcreteCommandPath(path.mEndpointId, path.mClusterId, path.mCommandId),
-                                   Protocols::InteractionModel::Status::Failure);
-    NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR);
+    commandHandler.AddStatus(ConcreteCommandPath(path.mEndpointId, path.mClusterId, path.mCommandId),
+                             Protocols::InteractionModel::Status::Failure);
     err = commandHandler.Finalize(commandPacket);
     NL_TEST_ASSERT(apSuite, err == CHIP_NO_ERROR);