project-chip · bzbarsky-apple · Dec 1, 2021 · Nov 23, 2021 · kpschoedel · Dec 2, 2021
diff --git a/.github/workflows/examples-nrfconnect.yaml b/.github/workflows/examples-nrfconnect.yaml
@@ -148,6 +148,14 @@ jobs:
               run: |
                   scripts/run_in_build_env.sh "scripts/tests/nrfconnect_native_posix_tests.sh native_posix_64"
 
+            - name: Uploading Failed Test Logs
+              uses: actions/upload-artifact@v2
+              if: ${{ failure() }} && ${{ !env.ACT }}
+              with:
+                  name: test-log
+                  path: |
+                      src/test_driver/nrfconnect/build/Testing/Temporary/LastTest.log
+
             - name: Uploading Size Reports
               uses: actions/upload-artifact@v2
               if: ${{ !env.ACT }}

diff --git a/examples/all-clusters-app/ameba/chip_main.cmake b/examples/all-clusters-app/ameba/chip_main.cmake
@@ -23,6 +23,7 @@ list(
     ${chip_dir}/src/app/EventManagement.cpp
     ${chip_dir}/src/app/ReadClient.cpp
     ${chip_dir}/src/app/ReadHandler.cpp
+    ${chip_dir}/src/app/TimedHandler.cpp
     ${chip_dir}/src/app/WriteClient.cpp
     ${chip_dir}/src/app/WriteHandler.cpp
     ${chip_dir}/src/app/util/CHIPDeviceCallbacksMgr.cpp

diff --git a/examples/lighting-app/ameba/chip_main.cmake b/examples/lighting-app/ameba/chip_main.cmake
@@ -23,6 +23,7 @@ list(
     ${chip_dir}/src/app/EventManagement.cpp
     ${chip_dir}/src/app/ReadClient.cpp
     ${chip_dir}/src/app/ReadHandler.cpp
+    ${chip_dir}/src/app/TimedHandler.cpp
     ${chip_dir}/src/app/WriteClient.cpp
     ${chip_dir}/src/app/WriteHandler.cpp
     ${chip_dir}/src/app/util/CHIPDeviceCallbacksMgr.cpp

diff --git a/scripts/tests/nrfconnect_native_posix_tests.sh b/scripts/tests/nrfconnect_native_posix_tests.sh
@@ -27,4 +27,4 @@ env
 cd "$CHIP_ROOT/src/test_driver/nrfconnect" &&
     west build -b "$BOARD" &&
     cd build &&
-    timeout 5m ctest -V
+    timeout 5m ctest -V --output-on-failure
diff --git a/src/app/BUILD.gn b/src/app/BUILD.gn
@@ -120,6 +120,8 @@ static_library("app") {
     "ReadHandler.cpp",
     "StatusResponse.cpp",
     "StatusResponse.h",
+    "TimedHandler.cpp",
+    "TimedHandler.h",
     "WriteClient.cpp",
     "WriteHandler.cpp",
     "decoder.cpp",

diff --git a/src/app/CommandHandler.cpp b/src/app/CommandHandler.cpp
@@ -63,7 +63,7 @@ CHIP_ERROR CommandHandler::AllocateBuffer()
 }
 
 CHIP_ERROR CommandHandler::OnInvokeCommandRequest(Messaging::ExchangeContext * ec, const PayloadHeader & payloadHeader,
-                                                  System::PacketBufferHandle && payload)
+                                                  System::PacketBufferHandle && payload, bool isTimedInvoke)
 {
     System::PacketBufferHandle response;
     VerifyOrReturnError(mState == CommandState::Idle, CHIP_ERROR_INCORRECT_STATE);
@@ -73,14 +73,18 @@ CHIP_ERROR CommandHandler::OnInvokeCommandRequest(Messaging::ExchangeContext * e
     mpExchangeCtx = ec;
 
     // Use the RAII feature, if this is the only Handle when this function returns, DecrementHoldOff will trigger sending response.
+    // TODO: This is broken!  If something under here returns error, we will try
+    // to SendCommandResponse(), and then our caller will try to send a status
+    // response too.  Figure out at what point it's our responsibility to
+    // handler errors vs our caller's.
     Handle workHandle(this);
     mpExchangeCtx->WillSendMessage();
-    ReturnErrorOnFailure(ProcessInvokeRequest(std::move(payload)));
+    ReturnErrorOnFailure(ProcessInvokeRequest(std::move(payload), isTimedInvoke));
 
     return CHIP_NO_ERROR;
 }
 
-CHIP_ERROR CommandHandler::ProcessInvokeRequest(System::PacketBufferHandle && payload)
+CHIP_ERROR CommandHandler::ProcessInvokeRequest(System::PacketBufferHandle && payload, bool isTimedInvoke)
 {
     CHIP_ERROR err = CHIP_NO_ERROR;
     System::PacketBufferTLVReader reader;
@@ -97,6 +101,29 @@ CHIP_ERROR CommandHandler::ProcessInvokeRequest(System::PacketBufferHandle && pa
     ReturnErrorOnFailure(invokeRequestMessage.GetTimedRequest(&mTimedRequest));
     ReturnErrorOnFailure(invokeRequestMessage.GetInvokeRequests(&invokeRequests));
 
+    if (mTimedRequest != isTimedInvoke)
+    {
+        // The message thinks it should be part of a timed interaction but it's
+        // not, or vice versa.  Spec says to Respond with UNSUPPORTED_ACCESS.
+        err = StatusResponse::SendStatusResponse(Protocols::InteractionModel::Status::UnsupportedAccess, mpExchangeCtx,
+                                                 /* aExpectResponse = */ false);
+
+        // Some unit tests call this function in an abnormal state when we don't
+        // even have an exchange.
+        if (err != CHIP_NO_ERROR && mpExchangeCtx)
+        {
+            // We have to manually close the exchange, because we called
+            // WillSendMessage already.
+            mpExchangeCtx->Close();
+        }
+
+        // Null out the (now-closed) exchange, so that when we try to
+        // SendCommandResponse() later (when our holdoff count drops to 0) it
+        // just fails and we don't double-respond.
+        mpExchangeCtx = nullptr;
+        return err;
+    }
+
     invokeRequests.GetReader(&invokeRequestsReader);
     while (CHIP_NO_ERROR == (err = invokeRequestsReader.Next()))
     {

diff --git a/src/app/CommandHandler.h b/src/app/CommandHandler.h
@@ -128,16 +128,20 @@ class CommandHandler : public Command
      *
      * This function will always call the OnDone function above on the registered callback
      * before returning.
+     *
+     * isTimedInvoke is true if and only if this is part of a Timed Invoke
+     * transaction (i.e. was preceded by a Timed Request).  If we reach here,
+     * the timer verification has already been done.
      */
     CHIP_ERROR OnInvokeCommandRequest(Messaging::ExchangeContext * ec, const PayloadHeader & payloadHeader,
-                                      System::PacketBufferHandle && payload);
+                                      System::PacketBufferHandle && payload, bool isTimedInvoke);
     CHIP_ERROR AddStatus(const ConcreteCommandPath & aCommandPath, const Protocols::InteractionModel::Status aStatus) override;
 
     CHIP_ERROR AddClusterSpecificSuccess(const ConcreteCommandPath & aCommandPath, ClusterStatus aClusterStatus) override;
 
     CHIP_ERROR AddClusterSpecificFailure(const ConcreteCommandPath & aCommandPath, ClusterStatus aClusterStatus) override;
 
-    CHIP_ERROR ProcessInvokeRequest(System::PacketBufferHandle && payload);
+    CHIP_ERROR ProcessInvokeRequest(System::PacketBufferHandle && payload, bool isTimedInvoke);
     CHIP_ERROR PrepareCommand(const CommandPathParams & aCommandPathParams, bool aStartDataStruct = true);
     CHIP_ERROR FinishCommand(bool aStartDataStruct = true);
     CHIP_ERROR PrepareStatus(const CommandPathParams & aCommandPathParams);
@@ -166,6 +170,11 @@ class CommandHandler : public Command
         return FinishCommand(/* aEndDataStruct = */ false);
     }
 
+    /**
+     * Check whether the InvokeRequest we are handling is a timed invoke.
+     */
+    bool IsTimedInvoke() const { return mTimedRequest; }
+
 private:
     friend class TestCommandInteraction;
     friend class CommandHandler::Handle;

diff --git a/src/app/InteractionModelEngine.cpp b/src/app/InteractionModelEngine.cpp
@@ -95,6 +95,15 @@ void InteractionModelEngine::Shutdown()
         return true;
     });
 
+    mTimedHandlers.ForEachActiveObject([this](TimedHandler * obj) -> bool {
+        // This calls back into us and deallocates |obj|.  As above, this is not
+        // really guaranteed, and we should do something better here (like
+        // ignoring the calls to OnTimedInteractionFailed and then doing a
+        // DeallocateAll.
+        mpExchangeMgr->CloseAllContextsForDelegate(obj);
+        return true;
+    });
+
     for (auto & readClient : mReadClients)
     {
         if (!readClient.IsFree())
@@ -277,7 +286,7 @@ void InteractionModelEngine::OnDone(CommandHandler & apCommandObj)
 
 CHIP_ERROR InteractionModelEngine::OnInvokeCommandRequest(Messaging::ExchangeContext * apExchangeContext,
                                                           const PayloadHeader & aPayloadHeader,
-                                                          System::PacketBufferHandle && aPayload,
+                                                          System::PacketBufferHandle && aPayload, bool aIsTimedInvoke,
                                                           Protocols::InteractionModel::Status & aStatus)
 {
     CommandHandler * commandHandler = mCommandHandlerObjs.CreateObject(this);
@@ -287,7 +296,8 @@ CHIP_ERROR InteractionModelEngine::OnInvokeCommandRequest(Messaging::ExchangeCon
         aStatus = Protocols::InteractionModel::Status::Busy;
         return CHIP_ERROR_NO_MEMORY;
     }
-    ReturnErrorOnFailure(commandHandler->OnInvokeCommandRequest(apExchangeContext, aPayloadHeader, std::move(aPayload)));
+    ReturnErrorOnFailure(
+        commandHandler->OnInvokeCommandRequest(apExchangeContext, aPayloadHeader, std::move(aPayload), aIsTimedInvoke));
     aStatus = Protocols::InteractionModel::Status::Success;
     return CHIP_NO_ERROR;
 }
@@ -360,6 +370,25 @@ CHIP_ERROR InteractionModelEngine::OnWriteRequest(Messaging::ExchangeContext * a
     return CHIP_NO_ERROR;
 }
 
+CHIP_ERROR InteractionModelEngine::OnTimedRequest(Messaging::ExchangeContext * apExchangeContext,
+                                                  const PayloadHeader & aPayloadHeader, System::PacketBufferHandle && aPayload,
+                                                  Protocols::InteractionModel::Status & aStatus)
+{
+    TimedHandler * handler = mTimedHandlers.CreateObject();
+    if (handler == nullptr)
+    {
+        ChipLogProgress(InteractionModel, "no resource for Timed interaction");
+        aStatus = Protocols::InteractionModel::Status::Busy;
+        return CHIP_ERROR_NO_MEMORY;
+    }
+
+    // The timed handler takes over handling of this exchange and will do its
+    // own status reporting as needed.
+    aStatus = Protocols::InteractionModel::Status::Success;
+    apExchangeContext->SetDelegate(handler);
+    return handler->OnMessageReceived(apExchangeContext, aPayloadHeader, std::move(aPayload));
+}
+
 CHIP_ERROR InteractionModelEngine::OnUnsolicitedReportData(Messaging::ExchangeContext * apExchangeContext,
                                                            const PayloadHeader & aPayloadHeader,
                                                            System::PacketBufferHandle && aPayload)
@@ -392,12 +421,15 @@ CHIP_ERROR InteractionModelEngine::OnUnsolicitedReportData(Messaging::ExchangeCo
 CHIP_ERROR InteractionModelEngine::OnMessageReceived(Messaging::ExchangeContext * apExchangeContext,
                                                      const PayloadHeader & aPayloadHeader, System::PacketBufferHandle && aPayload)
 {
+    using namespace Protocols::InteractionModel;
+
     CHIP_ERROR err                             = CHIP_NO_ERROR;
     Protocols::InteractionModel::Status status = Protocols::InteractionModel::Status::Failure;
 
     if (aPayloadHeader.HasMessageType(Protocols::InteractionModel::MsgType::InvokeCommandRequest))
     {
-        SuccessOrExit(OnInvokeCommandRequest(apExchangeContext, aPayloadHeader, std::move(aPayload), status));
+        SuccessOrExit(
+            OnInvokeCommandRequest(apExchangeContext, aPayloadHeader, std::move(aPayload), /* aIsTimedInvoke = */ false, status));
     }
     else if (aPayloadHeader.HasMessageType(Protocols::InteractionModel::MsgType::ReadRequest))
     {
@@ -418,6 +450,10 @@ CHIP_ERROR InteractionModelEngine::OnMessageReceived(Messaging::ExchangeContext
         ReturnErrorOnFailure(OnUnsolicitedReportData(apExchangeContext, aPayloadHeader, std::move(aPayload)));
         status = Protocols::InteractionModel::Status::Success;
     }
+    else if (aPayloadHeader.HasMessageType(MsgType::TimedRequest))
+    {
+        SuccessOrExit(OnTimedRequest(apExchangeContext, aPayloadHeader, std::move(aPayload), status));
+    }
     else
     {
         ChipLogProgress(InteractionModel, "Msg type %d not supported", aPayloadHeader.GetMessageType());
@@ -550,6 +586,9 @@ void InteractionModelEngine::DispatchCommand(CommandHandler & apCommandObj, cons
 
     if (handler)
     {
+        // TODO: Figure out who is responsible for handling checking
+        // apCommandObj->IsTimedInvoke() for commands that require a timed
+        // invoke and have a CommandHandlerInterface handling them.
         CommandHandlerInterface::HandlerContext context(apCommandObj, aCommandPath, apPayload);
         handler->InvokeCommand(context);
 
@@ -657,5 +696,31 @@ CommandHandlerInterface * InteractionModelEngine::FindCommandHandler(EndpointId
     return nullptr;
 }
 
+void InteractionModelEngine::OnTimedInteractionFailed(TimedHandler * apTimedHandler)
+{
+    mTimedHandlers.Deallocate(apTimedHandler);
+}
+
+void InteractionModelEngine::OnTimedInvoke(TimedHandler * apTimedHandler, Messaging::ExchangeContext * apExchangeContext,
+                                           const PayloadHeader & aPayloadHeader, System::PacketBufferHandle && aPayload)
+{
+    using namespace Protocols::InteractionModel;
+
+    // Reset the ourselves as the exchange delegate for now, to match what we'd
+    // do with an initial unsolicited invoke.
+    apExchangeContext->SetDelegate(this);
+    mTimedHandlers.Deallocate(apTimedHandler);
+
+    VerifyOrDie(aPayloadHeader.HasMessageType(MsgType::InvokeCommandRequest));
+    VerifyOrDie(!apExchangeContext->IsGroupExchangeContext());
+
+    Status status = Status::Failure;
+    OnInvokeCommandRequest(apExchangeContext, aPayloadHeader, std::move(aPayload), /* aIsTimedInvoke = */ true, status);
+    if (status != Status::Success)
+    {
+        StatusResponse::SendStatusResponse(status, apExchangeContext, /* aExpectResponse = */ false);
+    }
+}
+
 } // namespace app
 } // namespace chip
diff --git a/src/app/InteractionModelEngine.h b/src/app/InteractionModelEngine.h
@@ -48,6 +48,7 @@
 #include <app/ReadClient.h>
 #include <app/ReadHandler.h>
 #include <app/StatusResponse.h>
+#include <app/TimedHandler.h>
 #include <app/WriteClient.h>
 #include <app/WriteHandler.h>
 #include <app/reporting/Engine.h>
@@ -194,6 +195,20 @@ class InteractionModelEngine : public Messaging::ExchangeDelegate, public Comman
     CommandHandlerInterface * FindCommandHandler(EndpointId endpointId, ClusterId clusterId);
     void UnregisterCommandHandlers(EndpointId endpointId);
 
+    /**
+     * Called when a timed interaction has failed (i.e. the exchange it was
+     * happening on has closed while the exchange delegate was the timed
+     * handler).
+     */
+    void OnTimedInteractionFailed(TimedHandler * apTimedHandler);
+
+    /**
+     * Called when a timed invoke is received.  This function takes over all
+     * handling of the exchange, status reporting, and so forth.
+     */
+    void OnTimedInvoke(TimedHandler * apTimedHandler, Messaging::ExchangeContext * apExchangeContext,
+                       const PayloadHeader & aPayloadHeader, System::PacketBufferHandle && aPayload);
+
 private:
     friend class reporting::Engine;
     friend class TestCommandInteraction;
@@ -206,7 +221,8 @@ class InteractionModelEngine : public Messaging::ExchangeDelegate, public Comman
      * expected to set it to success if it does not want an automatic status response message to be sent.
      */
     CHIP_ERROR OnInvokeCommandRequest(Messaging::ExchangeContext * apExchangeContext, const PayloadHeader & aPayloadHeader,
-                                      System::PacketBufferHandle && aPayload, Protocols::InteractionModel::Status & aStatus);
+                                      System::PacketBufferHandle && aPayload, bool aIsTimedInvoke,
+                                      Protocols::InteractionModel::Status & aStatus);
     CHIP_ERROR OnMessageReceived(Messaging::ExchangeContext * apExchangeContext, const PayloadHeader & aPayloadHeader,
                                  System::PacketBufferHandle && aPayload) override;
     void OnResponseTimeout(Messaging::ExchangeContext * ec) override;
@@ -229,6 +245,14 @@ class InteractionModelEngine : public Messaging::ExchangeDelegate, public Comman
     CHIP_ERROR OnWriteRequest(Messaging::ExchangeContext * apExchangeContext, const PayloadHeader & aPayloadHeader,
                               System::PacketBufferHandle && aPayload, Protocols::InteractionModel::Status & aStatus);
 
+    /**
+     * Called when Interaction Model receives a Timed Request message.  Errors processing
+     * the Timed Request are handled entirely within this function. The caller pre-sets status to failure and the callee is
+     * expected to set it to success if it does not want an automatic status response message to be sent.
+     */
+    CHIP_ERROR OnTimedRequest(Messaging::ExchangeContext * apExchangeContext, const PayloadHeader & aPayloadHeader,
+                              System::PacketBufferHandle && aPayload, Protocols::InteractionModel::Status & aStatus);
+
     /**This function handles processing of un-solicited ReportData messages on the client, which can
      * only occur post subscription establishment
      */
@@ -247,6 +271,7 @@ class InteractionModelEngine : public Messaging::ExchangeDelegate, public Comman
     // TODO(#8006): investgate if we can disable some IM functions on some compact accessories.
     // TODO(#8006): investgate if we can provide more flexible object management on devices with more resources.
     BitMapObjectPool<CommandHandler, CHIP_IM_MAX_NUM_COMMAND_HANDLER> mCommandHandlerObjs;
+    BitMapObjectPool<TimedHandler, CHIP_IM_MAX_NUM_TIMED_HANDLER> mTimedHandlers;
     ReadClient mReadClients[CHIP_IM_MAX_NUM_READ_CLIENT];
     ReadHandler mReadHandlers[CHIP_IM_MAX_NUM_READ_HANDLER];
     WriteClient mWriteClients[CHIP_IM_MAX_NUM_WRITE_CLIENT];

diff --git a/src/app/MessageDef/InvokeRequestMessage.cpp b/src/app/MessageDef/InvokeRequestMessage.cpp
@@ -119,7 +119,7 @@ CHIP_ERROR InvokeRequestMessage::Parser::GetSuppressResponse(bool * const apSupp
 
 CHIP_ERROR InvokeRequestMessage::Parser::GetTimedRequest(bool * const apTimedRequest) const
 {
-    return GetSimpleValue(to_underlying(Tag::kSuppressResponse), TLV::kTLVType_Boolean, apTimedRequest);
+    return GetSimpleValue(to_underlying(Tag::kTimedRequest), TLV::kTLVType_Boolean, apTimedRequest);
 }
 
 CHIP_ERROR InvokeRequestMessage::Parser::GetInvokeRequests(InvokeRequests::Parser * const apInvokeRequests) const