From 5354f12f79864c1dc96606e76f785e722205309e Mon Sep 17 00:00:00 2001 From: Carol Yang Date: Fri, 5 Nov 2021 13:18:49 -0700 Subject: [PATCH 1/3] Log BDX messages --- src/protocols/bdx/BdxMessages.cpp | 105 ++++++++++++++++++++--- src/protocols/bdx/BdxMessages.h | 37 ++++++++ src/protocols/bdx/BdxTransferSession.cpp | 60 ++++++++++--- 3 files changed, 176 insertions(+), 26 deletions(-) diff --git a/src/protocols/bdx/BdxMessages.cpp b/src/protocols/bdx/BdxMessages.cpp index b9770a0bbad2f6..6e5df2f7cfe221 100644 --- a/src/protocols/bdx/BdxMessages.cpp +++ b/src/protocols/bdx/BdxMessages.cpp @@ -31,7 +31,8 @@ #include namespace { -constexpr uint8_t kVersionMask = 0x0F; +constexpr uint8_t kVersionMask = 0x0F; +constexpr uint8_t kMaxFileDesignatorLen = 32; } // namespace using namespace chip; @@ -99,17 +100,16 @@ CHIP_ERROR TransferInit::Parse(System::PacketBufferHandle aBuffer) uint32_t tmpUint32Value = 0; // Used for reading non-wide length and offset fields uint8_t * bufStart = aBuffer->Start(); Reader bufReader(bufStart, aBuffer->DataLength()); - BitFlags rangeCtlFlags; - SuccessOrExit(bufReader.Read8(&proposedTransferCtl).Read8(rangeCtlFlags.RawStorage()).Read16(&MaxBlockSize).StatusCode()); + SuccessOrExit(bufReader.Read8(&proposedTransferCtl).Read8(RangeCtlFlags.RawStorage()).Read16(&MaxBlockSize).StatusCode()); Version = proposedTransferCtl & kVersionMask; TransferCtlOptions.SetRaw(static_cast(proposedTransferCtl & ~kVersionMask)); StartOffset = 0; - if (rangeCtlFlags.Has(RangeControlFlags::kStartOffset)) + if (RangeCtlFlags.Has(RangeControlFlags::kStartOffset)) { - if (rangeCtlFlags.Has(RangeControlFlags::kWiderange)) + if (RangeCtlFlags.Has(RangeControlFlags::kWiderange)) { SuccessOrExit(bufReader.Read64(&StartOffset).StatusCode()); } @@ -121,9 +121,9 @@ CHIP_ERROR TransferInit::Parse(System::PacketBufferHandle aBuffer) } MaxLength = 0; - if (rangeCtlFlags.Has(RangeControlFlags::kDefLen)) + if (RangeCtlFlags.Has(RangeControlFlags::kDefLen)) { - if (rangeCtlFlags.Has(RangeControlFlags::kWiderange)) + if (RangeCtlFlags.Has(RangeControlFlags::kWiderange)) { SuccessOrExit(bufReader.Read64(&MaxLength).StatusCode()); } @@ -166,6 +166,32 @@ size_t TransferInit::MessageSize() const return WriteToBuffer(emptyBuf).Needed(); } +void TransferInit::LogMessage() const +{ + char fd[kMaxFileDesignatorLen]; + snprintf(fd, FileDesLength + 1, "%s", FileDesignator); + + switch (MessageType) + { + case MessageType::SendInit: + ChipLogProgress(BDX, "SendInit"); + break; + case MessageType::ReceiveInit: + ChipLogProgress(BDX, "ReceiveInit"); + break; + default: + break; + } + + ChipLogDetail(BDX, " Proposed Transfer Control: 0x%X", TransferCtlOptions.Raw() | Version); + ChipLogDetail(BDX, " Range Control: 0x%X", RangeCtlFlags.Raw()); + ChipLogDetail(BDX, " Proposed Max Block Size: %" PRIu16, MaxBlockSize); + ChipLogDetail(BDX, " Start Offset: 0x" ChipLogFormatX64, ChipLogValueX64(StartOffset)); + ChipLogDetail(BDX, " Proposed Max Length: 0x" ChipLogFormatX64, ChipLogValueX64(MaxLength)); + ChipLogDetail(BDX, " File Designator Length: %" PRIu16, FileDesLength); + ChipLogDetail(BDX, " File Designator: %s", fd); +} + bool TransferInit::operator==(const TransferInit & another) const { if ((MetadataLength != another.MetadataLength) || (FileDesLength != another.FileDesLength)) @@ -246,6 +272,13 @@ size_t SendAccept::MessageSize() const return WriteToBuffer(emptyBuf).Needed(); } +void SendAccept::LogMessage() const +{ + ChipLogProgress(BDX, "SendAccept"); + ChipLogDetail(BDX, " Transfer Control: 0x%X", TransferCtlFlags.Raw() | Version); + ChipLogDetail(BDX, " Max Block Size: %" PRIu16, MaxBlockSize); +} + bool SendAccept::operator==(const SendAccept & another) const { if (MetadataLength != another.MetadataLength) @@ -317,9 +350,8 @@ CHIP_ERROR ReceiveAccept::Parse(System::PacketBufferHandle aBuffer) uint32_t tmpUint32Value = 0; // Used for reading non-wide length and offset fields uint8_t * bufStart = aBuffer->Start(); Reader bufReader(bufStart, aBuffer->DataLength()); - BitFlags rangeCtlFlags; - SuccessOrExit(bufReader.Read8(&transferCtl).Read8(rangeCtlFlags.RawStorage()).Read16(&MaxBlockSize).StatusCode()); + SuccessOrExit(bufReader.Read8(&transferCtl).Read8(RangeCtlFlags.RawStorage()).Read16(&MaxBlockSize).StatusCode()); Version = transferCtl & kVersionMask; @@ -327,9 +359,9 @@ CHIP_ERROR ReceiveAccept::Parse(System::PacketBufferHandle aBuffer) TransferCtlFlags.SetRaw(static_cast(transferCtl & ~kVersionMask)); StartOffset = 0; - if (rangeCtlFlags.Has(RangeControlFlags::kStartOffset)) + if (RangeCtlFlags.Has(RangeControlFlags::kStartOffset)) { - if (rangeCtlFlags.Has(RangeControlFlags::kWiderange)) + if (RangeCtlFlags.Has(RangeControlFlags::kWiderange)) { SuccessOrExit(bufReader.Read64(&StartOffset).StatusCode()); } @@ -341,9 +373,9 @@ CHIP_ERROR ReceiveAccept::Parse(System::PacketBufferHandle aBuffer) } Length = 0; - if (rangeCtlFlags.Has(RangeControlFlags::kDefLen)) + if (RangeCtlFlags.Has(RangeControlFlags::kDefLen)) { - if (rangeCtlFlags.Has(RangeControlFlags::kWiderange)) + if (RangeCtlFlags.Has(RangeControlFlags::kWiderange)) { SuccessOrExit(bufReader.Read64(&Length).StatusCode()); } @@ -380,6 +412,15 @@ size_t ReceiveAccept::MessageSize() const return WriteToBuffer(emptyBuf).Needed(); } +void ReceiveAccept::LogMessage() const +{ + ChipLogProgress(BDX, "ReceiveAccept"); + ChipLogDetail(BDX, " Transfer Control: 0x%X", TransferCtlFlags.Raw() | Version); + ChipLogDetail(BDX, " Range Control: 0x%X", RangeCtlFlags.Raw()); + ChipLogDetail(BDX, " Max Block Size: %" PRIu16, MaxBlockSize); + ChipLogDetail(BDX, " Length: 0x" ChipLogFormatX64, ChipLogValueX64(Length)); +} + bool ReceiveAccept::operator==(const ReceiveAccept & another) const { if (MetadataLength != another.MetadataLength) @@ -423,6 +464,26 @@ bool CounterMessage::operator==(const CounterMessage & another) const return (BlockCounter == another.BlockCounter); } +void CounterMessage::LogMessage() const +{ + switch (MessageType) + { + case MessageType::BlockQuery: + ChipLogProgress(BDX, "BlockQuery"); + break; + case MessageType::BlockAck: + ChipLogProgress(BDX, "BlockAck"); + break; + case MessageType::BlockAckEOF: + ChipLogProgress(BDX, "BlockAckEOF"); + break; + default: + break; + } + + ChipLogDetail(BDX, " Block Counter: %" PRIu32, BlockCounter); +} + // WARNING: this function should never return early, since MessageSize() relies on it to calculate // the size of the message (even if the message is incomplete or filled out incorrectly). Encoding::LittleEndian::BufferWriter & DataBlock::WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const @@ -469,6 +530,24 @@ size_t DataBlock::MessageSize() const return WriteToBuffer(emptyBuf).Needed(); } +void DataBlock::LogMessage() const +{ + switch (MessageType) + { + case MessageType::Block: + ChipLogProgress(BDX, "Block"); + break; + case MessageType::BlockEOF: + ChipLogProgress(BDX, "BlockEOF"); + break; + default: + break; + } + + ChipLogDetail(BDX, " Block Counter: %" PRIu32, BlockCounter); + ChipLogDetail(BDX, " Data Length: %zu", DataLength); +} + bool DataBlock::operator==(const DataBlock & another) const { if (DataLength != another.DataLength) diff --git a/src/protocols/bdx/BdxMessages.h b/src/protocols/bdx/BdxMessages.h index ab15032a196e4e..555eabc1189cd5 100644 --- a/src/protocols/bdx/BdxMessages.h +++ b/src/protocols/bdx/BdxMessages.h @@ -120,6 +120,12 @@ struct BdxMessage */ virtual size_t MessageSize() const = 0; + /** + * @brief + * Log all parameters for this message. + */ + virtual void LogMessage() const = 0; + virtual ~BdxMessage() = default; }; @@ -129,6 +135,9 @@ struct BdxMessage */ struct TransferInit : public BdxMessage { + TransferInit() {} + TransferInit(bdx::MessageType messageType) { MessageType = messageType; } + /** * @brief * Equality check method. @@ -158,6 +167,12 @@ struct TransferInit : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; + void LogMessage() const override; + +private: + // These are only needed for logging purpose + bdx::MessageType MessageType; + BitFlags RangeCtlFlags; }; using SendInit = TransferInit; @@ -192,6 +207,7 @@ struct SendAccept : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; + void LogMessage() const override; }; /** @@ -226,6 +242,11 @@ struct ReceiveAccept : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; + void LogMessage() const override; + +private: + // This is only needed for logging purpose + BitFlags RangeCtlFlags; }; /** @@ -234,6 +255,9 @@ struct ReceiveAccept : public BdxMessage */ struct CounterMessage : public BdxMessage { + CounterMessage() {} + CounterMessage(bdx::MessageType messageType) { MessageType = messageType; } + /** * @brief * Equality check method. @@ -245,6 +269,11 @@ struct CounterMessage : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; + void LogMessage() const override; + +private: + // This is only needed for logging purpose + bdx::MessageType MessageType; }; using BlockQuery = CounterMessage; @@ -256,6 +285,9 @@ using BlockAckEOF = CounterMessage; */ struct DataBlock : public BdxMessage { + DataBlock() {} + DataBlock(bdx::MessageType messageType) { MessageType = messageType; } + /** * @brief * Equality check method. @@ -275,6 +307,11 @@ struct DataBlock : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; + void LogMessage() const override; + +private: + // This is only needed for logging purpose + bdx::MessageType MessageType; }; using Block = DataBlock; diff --git a/src/protocols/bdx/BdxTransferSession.cpp b/src/protocols/bdx/BdxTransferSession.cpp index 24c03fc78d316f..c2b8aa01e2dc39 100644 --- a/src/protocols/bdx/BdxTransferSession.cpp +++ b/src/protocols/bdx/BdxTransferSession.cpp @@ -145,7 +145,8 @@ CHIP_ERROR TransferSession::StartTransfer(TransferRole role, const TransferInitD mTransferLength = initData.Length; // Prepare TransferInit message - TransferInit initMsg; + const MessageType msgType = (mRole == TransferRole::kSender) ? MessageType::SendInit : MessageType::ReceiveInit; + TransferInit initMsg(msgType); initMsg.TransferCtlOptions = initData.TransferCtlFlags; initMsg.Version = kBdxVersion; initMsg.MaxBlockSize = mMaxSupportedBlockSize; @@ -158,7 +159,8 @@ CHIP_ERROR TransferSession::StartTransfer(TransferRole role, const TransferInitD ReturnErrorOnFailure(WriteToPacketBuffer(initMsg, mPendingMsgHandle)); - const MessageType msgType = (mRole == TransferRole::kSender) ? MessageType::SendInit : MessageType::ReceiveInit; + ChipLogProgress(BDX, "Sending BDX Message"); + initMsg.LogMessage(); mState = TransferState::kAwaitingAccept; mAwaitingResponse = true; @@ -216,6 +218,9 @@ CHIP_ERROR TransferSession::AcceptTransfer(const TransferAcceptData & acceptData ReturnErrorOnFailure(WriteToPacketBuffer(acceptMsg, mPendingMsgHandle)); msgType = MessageType::ReceiveAccept; + + ChipLogProgress(BDX, "Sending BDX Message"); + acceptMsg.LogMessage(); } else { @@ -228,6 +233,9 @@ CHIP_ERROR TransferSession::AcceptTransfer(const TransferAcceptData & acceptData ReturnErrorOnFailure(WriteToPacketBuffer(acceptMsg, mPendingMsgHandle)); msgType = MessageType::SendAccept; + + ChipLogProgress(BDX, "Sending BDX Message"); + acceptMsg.LogMessage(); } mState = TransferState::kTransferInProgress; @@ -252,11 +260,14 @@ CHIP_ERROR TransferSession::PrepareBlockQuery() VerifyOrReturnError(mPendingOutput == OutputEventType::kNone, CHIP_ERROR_INCORRECT_STATE); VerifyOrReturnError(!mAwaitingResponse, CHIP_ERROR_INCORRECT_STATE); - BlockQuery queryMsg; + BlockQuery queryMsg(msgType); queryMsg.BlockCounter = mNextQueryNum; ReturnErrorOnFailure(WriteToPacketBuffer(queryMsg, mPendingMsgHandle)); + ChipLogProgress(BDX, "Sending BDX Message"); + queryMsg.LogMessage(); + mAwaitingResponse = true; mLastQueryNum = mNextQueryNum++; @@ -275,14 +286,16 @@ CHIP_ERROR TransferSession::PrepareBlock(const BlockData & inData) // Verify non-zero data is provided and is no longer than MaxBlockSize (BlockEOF may contain 0 length data) VerifyOrReturnError((inData.Data != nullptr) && (inData.Length <= mTransferMaxBlockSize), CHIP_ERROR_INVALID_ARGUMENT); - DataBlock blockMsg; + const MessageType msgType = inData.IsEof ? MessageType::BlockEOF : MessageType::Block; + DataBlock blockMsg(msgType); blockMsg.BlockCounter = mNextBlockNum; blockMsg.Data = inData.Data; blockMsg.DataLength = inData.Length; ReturnErrorOnFailure(WriteToPacketBuffer(blockMsg, mPendingMsgHandle)); - const MessageType msgType = inData.IsEof ? MessageType::BlockEOF : MessageType::Block; + ChipLogProgress(BDX, "Sending BDX Message"); + blockMsg.LogMessage(); if (msgType == MessageType::BlockEOF) { @@ -304,12 +317,15 @@ CHIP_ERROR TransferSession::PrepareBlockAck() CHIP_ERROR_INCORRECT_STATE); VerifyOrReturnError(mPendingOutput == OutputEventType::kNone, CHIP_ERROR_INCORRECT_STATE); - CounterMessage ackMsg; - ackMsg.BlockCounter = mLastBlockNum; const MessageType msgType = (mState == TransferState::kReceivedEOF) ? MessageType::BlockAckEOF : MessageType::BlockAck; + CounterMessage ackMsg(msgType); + ackMsg.BlockCounter = mLastBlockNum; ReturnErrorOnFailure(WriteToPacketBuffer(ackMsg, mPendingMsgHandle)); + ChipLogProgress(BDX, "Sending BDX Message"); + ackMsg.LogMessage(); + if (mState == TransferState::kTransferInProgress) { if (mControlMode == TransferControlFlags::kSenderDrive) @@ -398,6 +414,8 @@ CHIP_ERROR TransferSession::HandleBdxMessage(const PayloadHeader & header, Syste const MessageType msgType = static_cast(header.GetMessageType()); + ChipLogProgress(BDX, "Handling received BDX Message"); + switch (msgType) { case MessageType::SendInit: @@ -470,7 +488,7 @@ void TransferSession::HandleTransferInit(MessageType msgType, System::PacketBuff VerifyOrReturn(msgType == MessageType::SendInit, PrepareStatusReport(StatusCode::kUnexpectedMessage)); } - TransferInit transferInit; + TransferInit transferInit(msgType); const CHIP_ERROR err = transferInit.Parse(msgData.Retain()); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); @@ -496,6 +514,8 @@ void TransferSession::HandleTransferInit(MessageType msgType, System::PacketBuff mPendingOutput = OutputEventType::kInitReceived; mState = TransferState::kNegotiateTransferParams; + + transferInit.LogMessage(); } void TransferSession::HandleReceiveAccept(System::PacketBufferHandle msgData) @@ -528,6 +548,8 @@ void TransferSession::HandleReceiveAccept(System::PacketBufferHandle msgData) mAwaitingResponse = (mControlMode == TransferControlFlags::kSenderDrive); mState = TransferState::kTransferInProgress; + + rcvAcceptMsg.LogMessage(); } void TransferSession::HandleSendAccept(System::PacketBufferHandle msgData) @@ -558,6 +580,8 @@ void TransferSession::HandleSendAccept(System::PacketBufferHandle msgData) mAwaitingResponse = (mControlMode == TransferControlFlags::kReceiverDrive); mState = TransferState::kTransferInProgress; + + sendAcceptMsg.LogMessage(); } void TransferSession::HandleBlockQuery(System::PacketBufferHandle msgData) @@ -566,7 +590,7 @@ void TransferSession::HandleBlockQuery(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kTransferInProgress, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - BlockQuery query; + BlockQuery query(MessageType::BlockQuery); const CHIP_ERROR err = query.Parse(std::move(msgData)); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); @@ -576,6 +600,8 @@ void TransferSession::HandleBlockQuery(System::PacketBufferHandle msgData) mAwaitingResponse = false; mLastQueryNum = query.BlockCounter; + + query.LogMessage(); } void TransferSession::HandleBlock(System::PacketBufferHandle msgData) @@ -584,7 +610,7 @@ void TransferSession::HandleBlock(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kTransferInProgress, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - Block blockMsg; + Block blockMsg(MessageType::Block); const CHIP_ERROR err = blockMsg.Parse(msgData.Retain()); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); @@ -609,6 +635,8 @@ void TransferSession::HandleBlock(System::PacketBufferHandle msgData) mLastBlockNum = blockMsg.BlockCounter; mAwaitingResponse = false; + + blockMsg.LogMessage(); } void TransferSession::HandleBlockEOF(System::PacketBufferHandle msgData) @@ -617,7 +645,7 @@ void TransferSession::HandleBlockEOF(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kTransferInProgress, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - BlockEOF blockEOFMsg; + BlockEOF blockEOFMsg(MessageType::BlockEOF); const CHIP_ERROR err = blockEOFMsg.Parse(msgData.Retain()); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); @@ -636,6 +664,8 @@ void TransferSession::HandleBlockEOF(System::PacketBufferHandle msgData) mAwaitingResponse = false; mState = TransferState::kReceivedEOF; + + blockEOFMsg.LogMessage(); } void TransferSession::HandleBlockAck(System::PacketBufferHandle msgData) @@ -644,7 +674,7 @@ void TransferSession::HandleBlockAck(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kTransferInProgress, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - BlockAck ackMsg; + BlockAck ackMsg(MessageType::BlockAck); const CHIP_ERROR err = ackMsg.Parse(std::move(msgData)); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); VerifyOrReturn(ackMsg.BlockCounter == mLastBlockNum, PrepareStatusReport(StatusCode::kBadBlockCounter)); @@ -654,6 +684,8 @@ void TransferSession::HandleBlockAck(System::PacketBufferHandle msgData) // In Receiver Drive, the Receiver can send a BlockAck to indicate receipt of the message and reset the timeout. // In this case, the Sender should wait to receive a BlockQuery next. mAwaitingResponse = (mControlMode == TransferControlFlags::kReceiverDrive); + + ackMsg.LogMessage(); } void TransferSession::HandleBlockAckEOF(System::PacketBufferHandle msgData) @@ -662,7 +694,7 @@ void TransferSession::HandleBlockAckEOF(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kAwaitingEOFAck, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - BlockAckEOF ackMsg; + BlockAckEOF ackMsg(MessageType::BlockAckEOF); const CHIP_ERROR err = ackMsg.Parse(std::move(msgData)); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); VerifyOrReturn(ackMsg.BlockCounter == mLastBlockNum, PrepareStatusReport(StatusCode::kBadBlockCounter)); @@ -672,6 +704,8 @@ void TransferSession::HandleBlockAckEOF(System::PacketBufferHandle msgData) mAwaitingResponse = false; mState = TransferState::kTransferDone; + + ackMsg.LogMessage(); } void TransferSession::ResolveTransferControlOptions(const BitFlags & proposed) From a8b972d49edb3e4f7569a3f8de0bf07cfd158688 Mon Sep 17 00:00:00 2001 From: Carol Yang Date: Mon, 8 Nov 2021 11:45:45 -0800 Subject: [PATCH 2/3] Create a new macro ChipLogAutomation - This macro is to be used only for test validation purpose --- src/lib/core/BUILD.gn | 1 + src/lib/core/CHIPConfig.h | 12 ++++ src/lib/core/core.gni | 3 + src/lib/support/logging/CHIPLogging.cpp | 1 + src/lib/support/logging/CHIPLogging.h | 27 +++++++- src/lib/support/logging/Constants.h | 12 +++- src/platform/qpg/args.gni | 1 + src/protocols/bdx/BdxMessages.cpp | 88 +++++++++++++----------- src/protocols/bdx/BdxMessages.h | 28 +++++--- src/protocols/bdx/BdxTransferSession.cpp | 44 ++++++++++-- 10 files changed, 160 insertions(+), 57 deletions(-) diff --git a/src/lib/core/BUILD.gn b/src/lib/core/BUILD.gn index f8eec50de42863..3c046222cdc25a 100644 --- a/src/lib/core/BUILD.gn +++ b/src/lib/core/BUILD.gn @@ -46,6 +46,7 @@ buildconfig_header("chip_buildconfig") { "CHIP_ERROR_LOGGING=${chip_error_logging}", "CHIP_PROGRESS_LOGGING=${chip_progress_logging}", "CHIP_DETAIL_LOGGING=${chip_detail_logging}", + "CHIP_AUTOMATION_LOGGING=${chip_automation_logging}", "CHIP_CONFIG_SHORT_ERROR_STR=${chip_config_short_error_str}", "CHIP_CONFIG_ENABLE_ARG_PARSER=${chip_config_enable_arg_parser}", "CHIP_TARGET_STYLE_UNIX=${chip_target_style_unix}", diff --git a/src/lib/core/CHIPConfig.h b/src/lib/core/CHIPConfig.h index 279e1cf49e5f59..d8137496b30e2b 100644 --- a/src/lib/core/CHIPConfig.h +++ b/src/lib/core/CHIPConfig.h @@ -1832,6 +1832,18 @@ #define CHIP_DETAIL_LOGGING 1 #endif // CHIP_DETAIL_LOGGING +/** + * @def CHIP_AUTOMATION_LOGGING + * + * @brief + * If asserted (1), enable logging of all messages in the + * chip::Logging::kLogCategory_Automation category. + * + */ +#ifndef CHIP_AUTOMATION_LOGGING +#define CHIP_AUTOMATION_LOGGING 1 +#endif // CHIP_AUTOMATION_LOGGING + /** * CHIP_CONFIG_LOG_MESSAGE_MAX_SIZE * diff --git a/src/lib/core/core.gni b/src/lib/core/core.gni index fdd43dabb6a90c..c33fd2af2b7b21 100644 --- a/src/lib/core/core.gni +++ b/src/lib/core/core.gni @@ -30,6 +30,9 @@ declare_args() { # Enable detail logging. chip_detail_logging = chip_logging + # Enable automation logging. + chip_automation_logging = chip_logging + # Enable short error strings. chip_config_short_error_str = false diff --git a/src/lib/support/logging/CHIPLogging.cpp b/src/lib/support/logging/CHIPLogging.cpp index df5439bd952697..57dacbe3f1b9f0 100644 --- a/src/lib/support/logging/CHIPLogging.cpp +++ b/src/lib/support/logging/CHIPLogging.cpp @@ -95,6 +95,7 @@ static const char ModuleNames[] = "-\0\0" // None "IM\0" // InteractionModel "TST" // Test "ODP" // OperationalDeviceProxy + "ATM" // Automation ; #define ModuleNamesCount ((sizeof(ModuleNames) - 1) / chip::Logging::kMaxModuleNameLen) diff --git a/src/lib/support/logging/CHIPLogging.h b/src/lib/support/logging/CHIPLogging.h index ac8f6820b2701f..8dfffd21288d1e 100644 --- a/src/lib/support/logging/CHIPLogging.h +++ b/src/lib/support/logging/CHIPLogging.h @@ -29,6 +29,7 @@ * - #CHIP_ERROR_LOGGING * - #CHIP_PROGRESS_LOGGING * - #CHIP_DETAIL_LOGGING + * - #CHIP_AUTOMATION_LOGGING * */ @@ -62,6 +63,7 @@ * - #CHIP_ERROR_LOGGING * - #CHIP_PROGRESS_LOGGING * - #CHIP_DETAIL_LOGGING + * - #CHIP_AUTOMATION_LOGGING * */ @@ -174,11 +176,32 @@ void SetLogFilter(uint8_t category); #define ChipLogByteSpan(MOD, DATA) ((void) 0) #endif -#if CHIP_ERROR_LOGGING || CHIP_PROGRESS_LOGGING || CHIP_DETAIL_LOGGING +#ifndef CHIP_AUTOMATION_LOGGING +#define CHIP_AUTOMATION_LOGGING 1 +#endif + +#if CHIP_AUTOMATION_LOGGING +/** + * @def ChipLogAutomation(MSG, ...) + * + * @brief + * Log a chip message for the specified module in the 'Automation' + * category. + * + */ +#ifndef ChipLogAutomation +#define ChipLogAutomation(MSG, ...) \ + chip::Logging::Log(chip::Logging::kLogModule_Automation, chip::Logging::kLogCategory_Automation, MSG, ##__VA_ARGS__) +#endif +#else +#define ChipLogAutomation(MOD, MSG, ...) ((void) 0) +#endif + +#if CHIP_ERROR_LOGGING || CHIP_PROGRESS_LOGGING || CHIP_DETAIL_LOGGING || CHIP_AUTOMATION_LOGGING #define _CHIP_USE_LOGGING 1 #else #define _CHIP_USE_LOGGING 0 -#endif /* CHIP_ERROR_LOGGING || CHIP_PROGRESS_LOGGING || CHIP_DETAIL_LOGGING */ +#endif /* CHIP_ERROR_LOGGING || CHIP_PROGRESS_LOGGING || CHIP_DETAIL_LOGGING || CHIP_AUTOMATION_LOGGING */ #if _CHIP_USE_LOGGING diff --git a/src/lib/support/logging/Constants.h b/src/lib/support/logging/Constants.h index ddc6beacbbf28e..0214fcaa2dbab8 100644 --- a/src/lib/support/logging/Constants.h +++ b/src/lib/support/logging/Constants.h @@ -57,6 +57,7 @@ enum LogModule kLogModule_InteractionModel, kLogModule_Test, kLogModule_OperationalDeviceProxy, + kLogModule_Automation, kLogModule_Max }; @@ -125,7 +126,16 @@ enum LogCategory */ kLogCategory_Detail = 3, - kLogCategory_Max = kLogCategory_Detail + /*!< + * Indicates a category of log message that describes automation + * information about an event or the state of the system. + * + * Such messages can be used by automation for test validation. + * + */ + kLogCategory_Automation = 4, + + kLogCategory_Max = kLogCategory_Automation }; } // namespace Logging diff --git a/src/platform/qpg/args.gni b/src/platform/qpg/args.gni index 28525a023d8256..a051e30b87bbbc 100644 --- a/src/platform/qpg/args.gni +++ b/src/platform/qpg/args.gni @@ -31,6 +31,7 @@ chip_inet_config_enable_tcp_endpoint = false # Size opt's #chip_progress_logging = false chip_detail_logging = false +chip_automation_logging = false # Use -Os is_debug = false diff --git a/src/protocols/bdx/BdxMessages.cpp b/src/protocols/bdx/BdxMessages.cpp index 6e5df2f7cfe221..72ffc40921c2d9 100644 --- a/src/protocols/bdx/BdxMessages.cpp +++ b/src/protocols/bdx/BdxMessages.cpp @@ -101,15 +101,15 @@ CHIP_ERROR TransferInit::Parse(System::PacketBufferHandle aBuffer) uint8_t * bufStart = aBuffer->Start(); Reader bufReader(bufStart, aBuffer->DataLength()); - SuccessOrExit(bufReader.Read8(&proposedTransferCtl).Read8(RangeCtlFlags.RawStorage()).Read16(&MaxBlockSize).StatusCode()); + SuccessOrExit(bufReader.Read8(&proposedTransferCtl).Read8(mRangeCtlFlags.RawStorage()).Read16(&MaxBlockSize).StatusCode()); Version = proposedTransferCtl & kVersionMask; TransferCtlOptions.SetRaw(static_cast(proposedTransferCtl & ~kVersionMask)); StartOffset = 0; - if (RangeCtlFlags.Has(RangeControlFlags::kStartOffset)) + if (mRangeCtlFlags.Has(RangeControlFlags::kStartOffset)) { - if (RangeCtlFlags.Has(RangeControlFlags::kWiderange)) + if (mRangeCtlFlags.Has(RangeControlFlags::kWiderange)) { SuccessOrExit(bufReader.Read64(&StartOffset).StatusCode()); } @@ -121,9 +121,9 @@ CHIP_ERROR TransferInit::Parse(System::PacketBufferHandle aBuffer) } MaxLength = 0; - if (RangeCtlFlags.Has(RangeControlFlags::kDefLen)) + if (mRangeCtlFlags.Has(RangeControlFlags::kDefLen)) { - if (RangeCtlFlags.Has(RangeControlFlags::kWiderange)) + if (mRangeCtlFlags.Has(RangeControlFlags::kWiderange)) { SuccessOrExit(bufReader.Read64(&MaxLength).StatusCode()); } @@ -166,31 +166,33 @@ size_t TransferInit::MessageSize() const return WriteToBuffer(emptyBuf).Needed(); } +#if CHIP_AUTOMATION_LOGGING void TransferInit::LogMessage() const { char fd[kMaxFileDesignatorLen]; - snprintf(fd, FileDesLength + 1, "%s", FileDesignator); + snprintf(fd, sizeof(fd), "%s", FileDesignator); - switch (MessageType) + switch (mMessageType) { case MessageType::SendInit: - ChipLogProgress(BDX, "SendInit"); + ChipLogAutomation("SendInit"); break; case MessageType::ReceiveInit: - ChipLogProgress(BDX, "ReceiveInit"); + ChipLogAutomation("ReceiveInit"); break; default: break; } - ChipLogDetail(BDX, " Proposed Transfer Control: 0x%X", TransferCtlOptions.Raw() | Version); - ChipLogDetail(BDX, " Range Control: 0x%X", RangeCtlFlags.Raw()); - ChipLogDetail(BDX, " Proposed Max Block Size: %" PRIu16, MaxBlockSize); - ChipLogDetail(BDX, " Start Offset: 0x" ChipLogFormatX64, ChipLogValueX64(StartOffset)); - ChipLogDetail(BDX, " Proposed Max Length: 0x" ChipLogFormatX64, ChipLogValueX64(MaxLength)); - ChipLogDetail(BDX, " File Designator Length: %" PRIu16, FileDesLength); - ChipLogDetail(BDX, " File Designator: %s", fd); + ChipLogAutomation(" Proposed Transfer Control: 0x%X", static_cast(TransferCtlOptions.Raw() | Version)); + ChipLogAutomation(" Range Control: 0x%X", static_cast(mRangeCtlFlags.Raw())); + ChipLogAutomation(" Proposed Max Block Size: %" PRIu16, MaxBlockSize); + ChipLogAutomation(" Start Offset: 0x" ChipLogFormatX64, ChipLogValueX64(StartOffset)); + ChipLogAutomation(" Proposed Max Length: 0x" ChipLogFormatX64, ChipLogValueX64(MaxLength)); + ChipLogAutomation(" File Designator Length: %" PRIu16, FileDesLength); + ChipLogAutomation(" File Designator: %s", fd); } +#endif // CHIP_AUTOMATION_LOGGING bool TransferInit::operator==(const TransferInit & another) const { @@ -272,12 +274,14 @@ size_t SendAccept::MessageSize() const return WriteToBuffer(emptyBuf).Needed(); } +#if CHIP_AUTOMATION_LOGGING void SendAccept::LogMessage() const { - ChipLogProgress(BDX, "SendAccept"); - ChipLogDetail(BDX, " Transfer Control: 0x%X", TransferCtlFlags.Raw() | Version); - ChipLogDetail(BDX, " Max Block Size: %" PRIu16, MaxBlockSize); + ChipLogAutomation("SendAccept"); + ChipLogAutomation(" Transfer Control: 0x%X", static_cast(TransferCtlFlags.Raw() | Version)); + ChipLogAutomation(" Max Block Size: %" PRIu16, MaxBlockSize); } +#endif // CHIP_AUTOMATION_LOGGING bool SendAccept::operator==(const SendAccept & another) const { @@ -351,7 +355,7 @@ CHIP_ERROR ReceiveAccept::Parse(System::PacketBufferHandle aBuffer) uint8_t * bufStart = aBuffer->Start(); Reader bufReader(bufStart, aBuffer->DataLength()); - SuccessOrExit(bufReader.Read8(&transferCtl).Read8(RangeCtlFlags.RawStorage()).Read16(&MaxBlockSize).StatusCode()); + SuccessOrExit(bufReader.Read8(&transferCtl).Read8(mRangeCtlFlags.RawStorage()).Read16(&MaxBlockSize).StatusCode()); Version = transferCtl & kVersionMask; @@ -359,9 +363,9 @@ CHIP_ERROR ReceiveAccept::Parse(System::PacketBufferHandle aBuffer) TransferCtlFlags.SetRaw(static_cast(transferCtl & ~kVersionMask)); StartOffset = 0; - if (RangeCtlFlags.Has(RangeControlFlags::kStartOffset)) + if (mRangeCtlFlags.Has(RangeControlFlags::kStartOffset)) { - if (RangeCtlFlags.Has(RangeControlFlags::kWiderange)) + if (mRangeCtlFlags.Has(RangeControlFlags::kWiderange)) { SuccessOrExit(bufReader.Read64(&StartOffset).StatusCode()); } @@ -373,9 +377,9 @@ CHIP_ERROR ReceiveAccept::Parse(System::PacketBufferHandle aBuffer) } Length = 0; - if (RangeCtlFlags.Has(RangeControlFlags::kDefLen)) + if (mRangeCtlFlags.Has(RangeControlFlags::kDefLen)) { - if (RangeCtlFlags.Has(RangeControlFlags::kWiderange)) + if (mRangeCtlFlags.Has(RangeControlFlags::kWiderange)) { SuccessOrExit(bufReader.Read64(&Length).StatusCode()); } @@ -412,14 +416,16 @@ size_t ReceiveAccept::MessageSize() const return WriteToBuffer(emptyBuf).Needed(); } +#if CHIP_AUTOMATION_LOGGING void ReceiveAccept::LogMessage() const { - ChipLogProgress(BDX, "ReceiveAccept"); - ChipLogDetail(BDX, " Transfer Control: 0x%X", TransferCtlFlags.Raw() | Version); - ChipLogDetail(BDX, " Range Control: 0x%X", RangeCtlFlags.Raw()); - ChipLogDetail(BDX, " Max Block Size: %" PRIu16, MaxBlockSize); - ChipLogDetail(BDX, " Length: 0x" ChipLogFormatX64, ChipLogValueX64(Length)); + ChipLogAutomation("ReceiveAccept"); + ChipLogAutomation(" Transfer Control: 0x%X", TransferCtlFlags.Raw() | Version); + ChipLogAutomation(" Range Control: 0x%X", mRangeCtlFlags.Raw()); + ChipLogAutomation(" Max Block Size: %" PRIu16, MaxBlockSize); + ChipLogAutomation(" Length: 0x" ChipLogFormatX64, ChipLogValueX64(Length)); } +#endif // CHIP_AUTOMATION_LOGGING bool ReceiveAccept::operator==(const ReceiveAccept & another) const { @@ -464,25 +470,27 @@ bool CounterMessage::operator==(const CounterMessage & another) const return (BlockCounter == another.BlockCounter); } +#if CHIP_AUTOMATION_LOGGING void CounterMessage::LogMessage() const { - switch (MessageType) + switch (mMessageType) { case MessageType::BlockQuery: - ChipLogProgress(BDX, "BlockQuery"); + ChipLogAutomation("BlockQuery"); break; case MessageType::BlockAck: - ChipLogProgress(BDX, "BlockAck"); + ChipLogAutomation("BlockAck"); break; case MessageType::BlockAckEOF: - ChipLogProgress(BDX, "BlockAckEOF"); + ChipLogAutomation("BlockAckEOF"); break; default: break; } - ChipLogDetail(BDX, " Block Counter: %" PRIu32, BlockCounter); + ChipLogAutomation(" Block Counter: %" PRIu32, BlockCounter); } +#endif // CHIP_AUTOMATION_LOGGING // WARNING: this function should never return early, since MessageSize() relies on it to calculate // the size of the message (even if the message is incomplete or filled out incorrectly). @@ -530,23 +538,25 @@ size_t DataBlock::MessageSize() const return WriteToBuffer(emptyBuf).Needed(); } +#if CHIP_AUTOMATION_LOGGING void DataBlock::LogMessage() const { - switch (MessageType) + switch (mMessageType) { case MessageType::Block: - ChipLogProgress(BDX, "Block"); + ChipLogAutomation("Block"); break; case MessageType::BlockEOF: - ChipLogProgress(BDX, "BlockEOF"); + ChipLogAutomation("BlockEOF"); break; default: break; } - ChipLogDetail(BDX, " Block Counter: %" PRIu32, BlockCounter); - ChipLogDetail(BDX, " Data Length: %zu", DataLength); + ChipLogAutomation(" Block Counter: %" PRIu32, BlockCounter); + ChipLogAutomation(" Data Length: %zu", DataLength); } +#endif // CHIP_AUTOMATION_LOGGING bool DataBlock::operator==(const DataBlock & another) const { diff --git a/src/protocols/bdx/BdxMessages.h b/src/protocols/bdx/BdxMessages.h index 555eabc1189cd5..99cbb08fd3215c 100644 --- a/src/protocols/bdx/BdxMessages.h +++ b/src/protocols/bdx/BdxMessages.h @@ -120,11 +120,13 @@ struct BdxMessage */ virtual size_t MessageSize() const = 0; +#if CHIP_AUTOMATION_LOGGING /** * @brief * Log all parameters for this message. */ virtual void LogMessage() const = 0; +#endif // CHIP_AUTOMATION_LOGGING virtual ~BdxMessage() = default; }; @@ -136,7 +138,7 @@ struct BdxMessage struct TransferInit : public BdxMessage { TransferInit() {} - TransferInit(bdx::MessageType messageType) { MessageType = messageType; } + TransferInit(bdx::MessageType messageType) { mMessageType = messageType; } /** * @brief @@ -167,12 +169,14 @@ struct TransferInit : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; +#if CHIP_AUTOMATION_LOGGING void LogMessage() const override; +#endif // CHIP_AUTOMATION_LOGGING private: // These are only needed for logging purpose - bdx::MessageType MessageType; - BitFlags RangeCtlFlags; + bdx::MessageType mMessageType; + BitFlags mRangeCtlFlags; }; using SendInit = TransferInit; @@ -207,7 +211,9 @@ struct SendAccept : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; +#if CHIP_AUTOMATION_LOGGING void LogMessage() const override; +#endif // CHIP_AUTOMATION_LOGGING }; /** @@ -242,11 +248,13 @@ struct ReceiveAccept : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; +#if CHIP_AUTOMATION_LOGGING void LogMessage() const override; +#endif // CHIP_AUTOMATION_LOGGING private: // This is only needed for logging purpose - BitFlags RangeCtlFlags; + BitFlags mRangeCtlFlags; }; /** @@ -256,7 +264,7 @@ struct ReceiveAccept : public BdxMessage struct CounterMessage : public BdxMessage { CounterMessage() {} - CounterMessage(bdx::MessageType messageType) { MessageType = messageType; } + CounterMessage(bdx::MessageType messageType) { mMessageType = messageType; } /** * @brief @@ -269,11 +277,13 @@ struct CounterMessage : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; +#if CHIP_AUTOMATION_LOGGING void LogMessage() const override; +#endif // CHIP_AUTOMATION_LOGGING private: // This is only needed for logging purpose - bdx::MessageType MessageType; + bdx::MessageType mMessageType; }; using BlockQuery = CounterMessage; @@ -286,7 +296,7 @@ using BlockAckEOF = CounterMessage; struct DataBlock : public BdxMessage { DataBlock() {} - DataBlock(bdx::MessageType messageType) { MessageType = messageType; } + DataBlock(bdx::MessageType messageType) { mMessageType = messageType; } /** * @brief @@ -307,11 +317,13 @@ struct DataBlock : public BdxMessage CHIP_ERROR Parse(System::PacketBufferHandle aBuffer) override; Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; +#if CHIP_AUTOMATION_LOGGING void LogMessage() const override; +#endif // CHIP_AUTOMATION_LOGGING private: // This is only needed for logging purpose - bdx::MessageType MessageType; + bdx::MessageType mMessageType; }; using Block = DataBlock; diff --git a/src/protocols/bdx/BdxTransferSession.cpp b/src/protocols/bdx/BdxTransferSession.cpp index c2b8aa01e2dc39..7ff0836f4a3b02 100644 --- a/src/protocols/bdx/BdxTransferSession.cpp +++ b/src/protocols/bdx/BdxTransferSession.cpp @@ -159,8 +159,10 @@ CHIP_ERROR TransferSession::StartTransfer(TransferRole role, const TransferInitD ReturnErrorOnFailure(WriteToPacketBuffer(initMsg, mPendingMsgHandle)); - ChipLogProgress(BDX, "Sending BDX Message"); +#if CHIP_AUTOMATION_LOGGING + ChipLogAutomation("Sending BDX Message"); initMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING mState = TransferState::kAwaitingAccept; mAwaitingResponse = true; @@ -219,8 +221,10 @@ CHIP_ERROR TransferSession::AcceptTransfer(const TransferAcceptData & acceptData ReturnErrorOnFailure(WriteToPacketBuffer(acceptMsg, mPendingMsgHandle)); msgType = MessageType::ReceiveAccept; - ChipLogProgress(BDX, "Sending BDX Message"); +#if CHIP_AUTOMATION_LOGGING + ChipLogAutomation("Sending BDX Message"); acceptMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } else { @@ -234,8 +238,10 @@ CHIP_ERROR TransferSession::AcceptTransfer(const TransferAcceptData & acceptData ReturnErrorOnFailure(WriteToPacketBuffer(acceptMsg, mPendingMsgHandle)); msgType = MessageType::SendAccept; - ChipLogProgress(BDX, "Sending BDX Message"); +#if CHIP_AUTOMATION_LOGGING + ChipLogAutomation("Sending BDX Message"); acceptMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } mState = TransferState::kTransferInProgress; @@ -265,8 +271,10 @@ CHIP_ERROR TransferSession::PrepareBlockQuery() ReturnErrorOnFailure(WriteToPacketBuffer(queryMsg, mPendingMsgHandle)); - ChipLogProgress(BDX, "Sending BDX Message"); +#if CHIP_AUTOMATION_LOGGING + ChipLogAutomation("Sending BDX Message"); queryMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING mAwaitingResponse = true; mLastQueryNum = mNextQueryNum++; @@ -294,8 +302,10 @@ CHIP_ERROR TransferSession::PrepareBlock(const BlockData & inData) ReturnErrorOnFailure(WriteToPacketBuffer(blockMsg, mPendingMsgHandle)); - ChipLogProgress(BDX, "Sending BDX Message"); +#if CHIP_AUTOMATION_LOGGING + ChipLogAutomation("Sending BDX Message"); blockMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING if (msgType == MessageType::BlockEOF) { @@ -323,8 +333,10 @@ CHIP_ERROR TransferSession::PrepareBlockAck() ReturnErrorOnFailure(WriteToPacketBuffer(ackMsg, mPendingMsgHandle)); - ChipLogProgress(BDX, "Sending BDX Message"); +#if CHIP_AUTOMATION_LOGGING + ChipLogAutomation("Sending BDX Message"); ackMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING if (mState == TransferState::kTransferInProgress) { @@ -414,7 +426,9 @@ CHIP_ERROR TransferSession::HandleBdxMessage(const PayloadHeader & header, Syste const MessageType msgType = static_cast(header.GetMessageType()); - ChipLogProgress(BDX, "Handling received BDX Message"); +#if CHIP_AUTOMATION_LOGGING + ChipLogAutomation("Handling received BDX Message"); +#endif // CHIP_AUTOMATION_LOGGING switch (msgType) { @@ -515,7 +529,9 @@ void TransferSession::HandleTransferInit(MessageType msgType, System::PacketBuff mState = TransferState::kNegotiateTransferParams; +#if CHIP_AUTOMATION_LOGGING transferInit.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } void TransferSession::HandleReceiveAccept(System::PacketBufferHandle msgData) @@ -549,7 +565,9 @@ void TransferSession::HandleReceiveAccept(System::PacketBufferHandle msgData) mAwaitingResponse = (mControlMode == TransferControlFlags::kSenderDrive); mState = TransferState::kTransferInProgress; +#if CHIP_AUTOMATION_LOGGING rcvAcceptMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } void TransferSession::HandleSendAccept(System::PacketBufferHandle msgData) @@ -581,7 +599,9 @@ void TransferSession::HandleSendAccept(System::PacketBufferHandle msgData) mAwaitingResponse = (mControlMode == TransferControlFlags::kReceiverDrive); mState = TransferState::kTransferInProgress; +#if CHIP_AUTOMATION_LOGGING sendAcceptMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } void TransferSession::HandleBlockQuery(System::PacketBufferHandle msgData) @@ -601,7 +621,9 @@ void TransferSession::HandleBlockQuery(System::PacketBufferHandle msgData) mAwaitingResponse = false; mLastQueryNum = query.BlockCounter; +#if CHIP_AUTOMATION_LOGGING query.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } void TransferSession::HandleBlock(System::PacketBufferHandle msgData) @@ -636,7 +658,9 @@ void TransferSession::HandleBlock(System::PacketBufferHandle msgData) mAwaitingResponse = false; +#if CHIP_AUTOMATION_LOGGING blockMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } void TransferSession::HandleBlockEOF(System::PacketBufferHandle msgData) @@ -665,7 +689,9 @@ void TransferSession::HandleBlockEOF(System::PacketBufferHandle msgData) mAwaitingResponse = false; mState = TransferState::kReceivedEOF; +#if CHIP_AUTOMATION_LOGGING blockEOFMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } void TransferSession::HandleBlockAck(System::PacketBufferHandle msgData) @@ -685,7 +711,9 @@ void TransferSession::HandleBlockAck(System::PacketBufferHandle msgData) // In this case, the Sender should wait to receive a BlockQuery next. mAwaitingResponse = (mControlMode == TransferControlFlags::kReceiverDrive); +#if CHIP_AUTOMATION_LOGGING ackMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } void TransferSession::HandleBlockAckEOF(System::PacketBufferHandle msgData) @@ -705,7 +733,9 @@ void TransferSession::HandleBlockAckEOF(System::PacketBufferHandle msgData) mState = TransferState::kTransferDone; +#if CHIP_AUTOMATION_LOGGING ackMsg.LogMessage(); +#endif // CHIP_AUTOMATION_LOGGING } void TransferSession::ResolveTransferControlOptions(const BitFlags & proposed) From d9dfb5a42c4be3e50009fbb163d9d0bad1cca80d Mon Sep 17 00:00:00 2001 From: Carol Yang Date: Mon, 8 Nov 2021 13:04:48 -0800 Subject: [PATCH 3/3] Remove private struct members from BdxMessage types - Pass in the message type directly during logging --- src/protocols/bdx/BdxMessages.cpp | 18 ++++---- src/protocols/bdx/BdxMessages.h | 44 +++++-------------- src/protocols/bdx/BdxTransferSession.cpp | 56 ++++++++++++------------ 3 files changed, 51 insertions(+), 67 deletions(-) diff --git a/src/protocols/bdx/BdxMessages.cpp b/src/protocols/bdx/BdxMessages.cpp index 72ffc40921c2d9..9c0e24c273f07e 100644 --- a/src/protocols/bdx/BdxMessages.cpp +++ b/src/protocols/bdx/BdxMessages.cpp @@ -167,12 +167,12 @@ size_t TransferInit::MessageSize() const } #if CHIP_AUTOMATION_LOGGING -void TransferInit::LogMessage() const +void TransferInit::LogMessage(bdx::MessageType messageType) const { char fd[kMaxFileDesignatorLen]; snprintf(fd, sizeof(fd), "%s", FileDesignator); - switch (mMessageType) + switch (messageType) { case MessageType::SendInit: ChipLogAutomation("SendInit"); @@ -275,8 +275,9 @@ size_t SendAccept::MessageSize() const } #if CHIP_AUTOMATION_LOGGING -void SendAccept::LogMessage() const +void SendAccept::LogMessage(bdx::MessageType messageType) const { + (void) messageType; ChipLogAutomation("SendAccept"); ChipLogAutomation(" Transfer Control: 0x%X", static_cast(TransferCtlFlags.Raw() | Version)); ChipLogAutomation(" Max Block Size: %" PRIu16, MaxBlockSize); @@ -417,8 +418,9 @@ size_t ReceiveAccept::MessageSize() const } #if CHIP_AUTOMATION_LOGGING -void ReceiveAccept::LogMessage() const +void ReceiveAccept::LogMessage(bdx::MessageType messageType) const { + (void) messageType; ChipLogAutomation("ReceiveAccept"); ChipLogAutomation(" Transfer Control: 0x%X", TransferCtlFlags.Raw() | Version); ChipLogAutomation(" Range Control: 0x%X", mRangeCtlFlags.Raw()); @@ -471,9 +473,9 @@ bool CounterMessage::operator==(const CounterMessage & another) const } #if CHIP_AUTOMATION_LOGGING -void CounterMessage::LogMessage() const +void CounterMessage::LogMessage(bdx::MessageType messageType) const { - switch (mMessageType) + switch (messageType) { case MessageType::BlockQuery: ChipLogAutomation("BlockQuery"); @@ -539,9 +541,9 @@ size_t DataBlock::MessageSize() const } #if CHIP_AUTOMATION_LOGGING -void DataBlock::LogMessage() const +void DataBlock::LogMessage(bdx::MessageType messageType) const { - switch (mMessageType) + switch (messageType) { case MessageType::Block: ChipLogAutomation("Block"); diff --git a/src/protocols/bdx/BdxMessages.h b/src/protocols/bdx/BdxMessages.h index 99cbb08fd3215c..880008b6956f24 100644 --- a/src/protocols/bdx/BdxMessages.h +++ b/src/protocols/bdx/BdxMessages.h @@ -125,7 +125,7 @@ struct BdxMessage * @brief * Log all parameters for this message. */ - virtual void LogMessage() const = 0; + virtual void LogMessage(bdx::MessageType messageType) const = 0; #endif // CHIP_AUTOMATION_LOGGING virtual ~BdxMessage() = default; @@ -137,9 +137,6 @@ struct BdxMessage */ struct TransferInit : public BdxMessage { - TransferInit() {} - TransferInit(bdx::MessageType messageType) { mMessageType = messageType; } - /** * @brief * Equality check method. @@ -150,6 +147,9 @@ struct TransferInit : public BdxMessage BitFlags TransferCtlOptions; uint8_t Version = 0; ///< The highest version supported by the sender + // Range Control + BitFlags mRangeCtlFlags; + // All required uint16_t MaxBlockSize = 0; ///< Proposed max block size to use in transfer uint64_t StartOffset = 0; ///< Proposed start offset of data. 0 for no offset @@ -170,13 +170,8 @@ struct TransferInit : public BdxMessage Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; #if CHIP_AUTOMATION_LOGGING - void LogMessage() const override; + void LogMessage(bdx::MessageType messageType) const override; #endif // CHIP_AUTOMATION_LOGGING - -private: - // These are only needed for logging purpose - bdx::MessageType mMessageType; - BitFlags mRangeCtlFlags; }; using SendInit = TransferInit; @@ -212,7 +207,7 @@ struct SendAccept : public BdxMessage Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; #if CHIP_AUTOMATION_LOGGING - void LogMessage() const override; + void LogMessage(bdx::MessageType messageType) const override; #endif // CHIP_AUTOMATION_LOGGING }; @@ -230,6 +225,9 @@ struct ReceiveAccept : public BdxMessage // Transfer Control (required, only one should be set) BitFlags TransferCtlFlags; + // Range Control + BitFlags mRangeCtlFlags; + // All required uint8_t Version = 0; ///< The agreed upon version for the transfer uint16_t MaxBlockSize = 0; ///< Chosen max block size to use in transfer @@ -249,12 +247,8 @@ struct ReceiveAccept : public BdxMessage Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; #if CHIP_AUTOMATION_LOGGING - void LogMessage() const override; + void LogMessage(bdx::MessageType messageType) const override; #endif // CHIP_AUTOMATION_LOGGING - -private: - // This is only needed for logging purpose - BitFlags mRangeCtlFlags; }; /** @@ -263,9 +257,6 @@ struct ReceiveAccept : public BdxMessage */ struct CounterMessage : public BdxMessage { - CounterMessage() {} - CounterMessage(bdx::MessageType messageType) { mMessageType = messageType; } - /** * @brief * Equality check method. @@ -278,12 +269,8 @@ struct CounterMessage : public BdxMessage Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; #if CHIP_AUTOMATION_LOGGING - void LogMessage() const override; + void LogMessage(bdx::MessageType messageType) const override; #endif // CHIP_AUTOMATION_LOGGING - -private: - // This is only needed for logging purpose - bdx::MessageType mMessageType; }; using BlockQuery = CounterMessage; @@ -295,9 +282,6 @@ using BlockAckEOF = CounterMessage; */ struct DataBlock : public BdxMessage { - DataBlock() {} - DataBlock(bdx::MessageType messageType) { mMessageType = messageType; } - /** * @brief * Equality check method. @@ -318,12 +302,8 @@ struct DataBlock : public BdxMessage Encoding::LittleEndian::BufferWriter & WriteToBuffer(Encoding::LittleEndian::BufferWriter & aBuffer) const override; size_t MessageSize() const override; #if CHIP_AUTOMATION_LOGGING - void LogMessage() const override; + void LogMessage(bdx::MessageType messageType) const override; #endif // CHIP_AUTOMATION_LOGGING - -private: - // This is only needed for logging purpose - bdx::MessageType mMessageType; }; using Block = DataBlock; diff --git a/src/protocols/bdx/BdxTransferSession.cpp b/src/protocols/bdx/BdxTransferSession.cpp index 7ff0836f4a3b02..96aa2d205b71d9 100644 --- a/src/protocols/bdx/BdxTransferSession.cpp +++ b/src/protocols/bdx/BdxTransferSession.cpp @@ -145,8 +145,7 @@ CHIP_ERROR TransferSession::StartTransfer(TransferRole role, const TransferInitD mTransferLength = initData.Length; // Prepare TransferInit message - const MessageType msgType = (mRole == TransferRole::kSender) ? MessageType::SendInit : MessageType::ReceiveInit; - TransferInit initMsg(msgType); + TransferInit initMsg; initMsg.TransferCtlOptions = initData.TransferCtlFlags; initMsg.Version = kBdxVersion; initMsg.MaxBlockSize = mMaxSupportedBlockSize; @@ -159,9 +158,11 @@ CHIP_ERROR TransferSession::StartTransfer(TransferRole role, const TransferInitD ReturnErrorOnFailure(WriteToPacketBuffer(initMsg, mPendingMsgHandle)); + const MessageType msgType = (mRole == TransferRole::kSender) ? MessageType::SendInit : MessageType::ReceiveInit; + #if CHIP_AUTOMATION_LOGGING ChipLogAutomation("Sending BDX Message"); - initMsg.LogMessage(); + initMsg.LogMessage(msgType); #endif // CHIP_AUTOMATION_LOGGING mState = TransferState::kAwaitingAccept; @@ -223,7 +224,7 @@ CHIP_ERROR TransferSession::AcceptTransfer(const TransferAcceptData & acceptData #if CHIP_AUTOMATION_LOGGING ChipLogAutomation("Sending BDX Message"); - acceptMsg.LogMessage(); + acceptMsg.LogMessage(msgType); #endif // CHIP_AUTOMATION_LOGGING } else @@ -240,7 +241,7 @@ CHIP_ERROR TransferSession::AcceptTransfer(const TransferAcceptData & acceptData #if CHIP_AUTOMATION_LOGGING ChipLogAutomation("Sending BDX Message"); - acceptMsg.LogMessage(); + acceptMsg.LogMessage(msgType); #endif // CHIP_AUTOMATION_LOGGING } @@ -266,14 +267,14 @@ CHIP_ERROR TransferSession::PrepareBlockQuery() VerifyOrReturnError(mPendingOutput == OutputEventType::kNone, CHIP_ERROR_INCORRECT_STATE); VerifyOrReturnError(!mAwaitingResponse, CHIP_ERROR_INCORRECT_STATE); - BlockQuery queryMsg(msgType); + BlockQuery queryMsg; queryMsg.BlockCounter = mNextQueryNum; ReturnErrorOnFailure(WriteToPacketBuffer(queryMsg, mPendingMsgHandle)); #if CHIP_AUTOMATION_LOGGING ChipLogAutomation("Sending BDX Message"); - queryMsg.LogMessage(); + queryMsg.LogMessage(msgType); #endif // CHIP_AUTOMATION_LOGGING mAwaitingResponse = true; @@ -294,17 +295,18 @@ CHIP_ERROR TransferSession::PrepareBlock(const BlockData & inData) // Verify non-zero data is provided and is no longer than MaxBlockSize (BlockEOF may contain 0 length data) VerifyOrReturnError((inData.Data != nullptr) && (inData.Length <= mTransferMaxBlockSize), CHIP_ERROR_INVALID_ARGUMENT); - const MessageType msgType = inData.IsEof ? MessageType::BlockEOF : MessageType::Block; - DataBlock blockMsg(msgType); + DataBlock blockMsg; blockMsg.BlockCounter = mNextBlockNum; blockMsg.Data = inData.Data; blockMsg.DataLength = inData.Length; ReturnErrorOnFailure(WriteToPacketBuffer(blockMsg, mPendingMsgHandle)); + const MessageType msgType = inData.IsEof ? MessageType::BlockEOF : MessageType::Block; + #if CHIP_AUTOMATION_LOGGING ChipLogAutomation("Sending BDX Message"); - blockMsg.LogMessage(); + blockMsg.LogMessage(msgType); #endif // CHIP_AUTOMATION_LOGGING if (msgType == MessageType::BlockEOF) @@ -327,15 +329,15 @@ CHIP_ERROR TransferSession::PrepareBlockAck() CHIP_ERROR_INCORRECT_STATE); VerifyOrReturnError(mPendingOutput == OutputEventType::kNone, CHIP_ERROR_INCORRECT_STATE); + CounterMessage ackMsg; + ackMsg.BlockCounter = mLastBlockNum; const MessageType msgType = (mState == TransferState::kReceivedEOF) ? MessageType::BlockAckEOF : MessageType::BlockAck; - CounterMessage ackMsg(msgType); - ackMsg.BlockCounter = mLastBlockNum; ReturnErrorOnFailure(WriteToPacketBuffer(ackMsg, mPendingMsgHandle)); #if CHIP_AUTOMATION_LOGGING ChipLogAutomation("Sending BDX Message"); - ackMsg.LogMessage(); + ackMsg.LogMessage(msgType); #endif // CHIP_AUTOMATION_LOGGING if (mState == TransferState::kTransferInProgress) @@ -502,7 +504,7 @@ void TransferSession::HandleTransferInit(MessageType msgType, System::PacketBuff VerifyOrReturn(msgType == MessageType::SendInit, PrepareStatusReport(StatusCode::kUnexpectedMessage)); } - TransferInit transferInit(msgType); + TransferInit transferInit; const CHIP_ERROR err = transferInit.Parse(msgData.Retain()); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); @@ -530,7 +532,7 @@ void TransferSession::HandleTransferInit(MessageType msgType, System::PacketBuff mState = TransferState::kNegotiateTransferParams; #if CHIP_AUTOMATION_LOGGING - transferInit.LogMessage(); + transferInit.LogMessage(msgType); #endif // CHIP_AUTOMATION_LOGGING } @@ -566,7 +568,7 @@ void TransferSession::HandleReceiveAccept(System::PacketBufferHandle msgData) mState = TransferState::kTransferInProgress; #if CHIP_AUTOMATION_LOGGING - rcvAcceptMsg.LogMessage(); + rcvAcceptMsg.LogMessage(MessageType::ReceiveAccept); #endif // CHIP_AUTOMATION_LOGGING } @@ -600,7 +602,7 @@ void TransferSession::HandleSendAccept(System::PacketBufferHandle msgData) mState = TransferState::kTransferInProgress; #if CHIP_AUTOMATION_LOGGING - sendAcceptMsg.LogMessage(); + sendAcceptMsg.LogMessage(MessageType::SendAccept); #endif // CHIP_AUTOMATION_LOGGING } @@ -610,7 +612,7 @@ void TransferSession::HandleBlockQuery(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kTransferInProgress, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - BlockQuery query(MessageType::BlockQuery); + BlockQuery query; const CHIP_ERROR err = query.Parse(std::move(msgData)); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); @@ -622,7 +624,7 @@ void TransferSession::HandleBlockQuery(System::PacketBufferHandle msgData) mLastQueryNum = query.BlockCounter; #if CHIP_AUTOMATION_LOGGING - query.LogMessage(); + query.LogMessage(MessageType::BlockQuery); #endif // CHIP_AUTOMATION_LOGGING } @@ -632,7 +634,7 @@ void TransferSession::HandleBlock(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kTransferInProgress, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - Block blockMsg(MessageType::Block); + Block blockMsg; const CHIP_ERROR err = blockMsg.Parse(msgData.Retain()); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); @@ -659,7 +661,7 @@ void TransferSession::HandleBlock(System::PacketBufferHandle msgData) mAwaitingResponse = false; #if CHIP_AUTOMATION_LOGGING - blockMsg.LogMessage(); + blockMsg.LogMessage(MessageType::Block); #endif // CHIP_AUTOMATION_LOGGING } @@ -669,7 +671,7 @@ void TransferSession::HandleBlockEOF(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kTransferInProgress, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - BlockEOF blockEOFMsg(MessageType::BlockEOF); + BlockEOF blockEOFMsg; const CHIP_ERROR err = blockEOFMsg.Parse(msgData.Retain()); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); @@ -690,7 +692,7 @@ void TransferSession::HandleBlockEOF(System::PacketBufferHandle msgData) mState = TransferState::kReceivedEOF; #if CHIP_AUTOMATION_LOGGING - blockEOFMsg.LogMessage(); + blockEOFMsg.LogMessage(MessageType::BlockEOF); #endif // CHIP_AUTOMATION_LOGGING } @@ -700,7 +702,7 @@ void TransferSession::HandleBlockAck(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kTransferInProgress, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - BlockAck ackMsg(MessageType::BlockAck); + BlockAck ackMsg; const CHIP_ERROR err = ackMsg.Parse(std::move(msgData)); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); VerifyOrReturn(ackMsg.BlockCounter == mLastBlockNum, PrepareStatusReport(StatusCode::kBadBlockCounter)); @@ -712,7 +714,7 @@ void TransferSession::HandleBlockAck(System::PacketBufferHandle msgData) mAwaitingResponse = (mControlMode == TransferControlFlags::kReceiverDrive); #if CHIP_AUTOMATION_LOGGING - ackMsg.LogMessage(); + ackMsg.LogMessage(MessageType::BlockAck); #endif // CHIP_AUTOMATION_LOGGING } @@ -722,7 +724,7 @@ void TransferSession::HandleBlockAckEOF(System::PacketBufferHandle msgData) VerifyOrReturn(mState == TransferState::kAwaitingEOFAck, PrepareStatusReport(StatusCode::kUnexpectedMessage)); VerifyOrReturn(mAwaitingResponse, PrepareStatusReport(StatusCode::kUnexpectedMessage)); - BlockAckEOF ackMsg(MessageType::BlockAckEOF); + BlockAckEOF ackMsg; const CHIP_ERROR err = ackMsg.Parse(std::move(msgData)); VerifyOrReturn(err == CHIP_NO_ERROR, PrepareStatusReport(StatusCode::kBadMessageContents)); VerifyOrReturn(ackMsg.BlockCounter == mLastBlockNum, PrepareStatusReport(StatusCode::kBadBlockCounter)); @@ -734,7 +736,7 @@ void TransferSession::HandleBlockAckEOF(System::PacketBufferHandle msgData) mState = TransferState::kTransferDone; #if CHIP_AUTOMATION_LOGGING - ackMsg.LogMessage(); + ackMsg.LogMessage(MessageType::BlockAckEOF); #endif // CHIP_AUTOMATION_LOGGING }