From 91b7c3ff3f178a212c94f18662a3b4e3f400d721 Mon Sep 17 00:00:00 2001 From: Abtin Keshavarzian Date: Wed, 25 Oct 2023 14:54:33 -0700 Subject: [PATCH] [log] add `otLogGenerateNextHexDumpLine()` to generate hex dump (#9555) This commit adds a public OT API to generate hex dump output line by line. This function is then used for both `LogDump{}()` and frame capture output by CLI `promiscuous` command (removing repeated similar code) and harmonize the hex dump outputs. --- include/openthread/instance.h | 2 +- include/openthread/logging.h | 39 +++++ src/cli/cli.cpp | 65 +------- src/core/api/logging_api.cpp | 7 + src/core/common/log.cpp | 154 +++++++++++-------- src/core/common/log.hpp | 30 +++- src/core/common/string.cpp | 10 ++ src/core/common/string.hpp | 9 ++ tests/scripts/expect/cli-promiscuous.exp | 5 +- tests/toranj/openthread-core-toranj-config.h | 2 +- 10 files changed, 192 insertions(+), 131 deletions(-) diff --git a/include/openthread/instance.h b/include/openthread/instance.h index f1115e5f7cd..b9c0b82b1b0 100644 --- a/include/openthread/instance.h +++ b/include/openthread/instance.h @@ -53,7 +53,7 @@ extern "C" { * @note This number versions both OpenThread platform and user APIs. * */ -#define OPENTHREAD_API_VERSION (368) +#define OPENTHREAD_API_VERSION (369) /** * @addtogroup api-instance diff --git a/include/openthread/logging.h b/include/openthread/logging.h index 1f989851aba..c0fb61002a1 100644 --- a/include/openthread/logging.h +++ b/include/openthread/logging.h @@ -253,6 +253,45 @@ void otLogPlatArgs(otLogLevel aLogLevel, const char *aPlatModuleName, const char */ void otLogCli(otLogLevel aLogLevel, const char *aFormat, ...) OT_TOOL_PRINTF_STYLE_FORMAT_ARG_CHECK(2, 3); +#define OT_LOG_HEX_DUMP_LINE_SIZE 73 ///< Hex dump line string size. + +/** + * Represents information used for generating hex dump output. + * + */ +typedef struct +{ + const uint8_t *mDataBytes; ///< The data byes. + uint16_t mDataLength; ///< The data length (number of bytes in @p mDataBytes) + const char *mTitle; ///< Title string to add table header (MUST NOT be `NULL`). + char mLine[OT_LOG_HEX_DUMP_LINE_SIZE]; ///< Buffer to output one line of generated hex dump. + uint16_t mIterator; ///< Iterator used by OT stack. MUST be initialized to zero. +} otLogHexDumpInfo; + +/** + * Generates the next hex dump line. + * + * Can call this method back-to-back to generate the hex dump output line by line. On the first call the `mIterator` + * field in @p aInfo MUST be set to zero. + * + * Here is an example of the generated hex dump output: + * + * "==========================[{mTitle} len=070]============================" + * "| 41 D8 87 34 12 FF FF 25 | 4C 57 DA F2 FB 2F 62 7F | A..4...%LW.../b. |" + * "| 3B 01 F0 4D 4C 4D 4C 54 | 4F 00 15 15 00 00 00 00 | ;..MLMLTO....... |" + * "| 00 00 00 01 80 DB 60 82 | 7E 33 72 3B CC B3 A1 84 | ......`.~3r;.... |" + * "| 3B E6 AD B2 0B 45 E7 45 | C5 B9 00 1A CB 2D 6D 1C | ;....E.E.....-m. |" + * "| 10 3E 3C F5 D3 70 | | .><..p |" + * "------------------------------------------------------------------------" + * + * @param[in,out] aInfo A pointer to `otLogHexDumpInfo` to use to generate hex dump. + * + * @retval OT_ERROR_NONE Successfully generated the next line, `mLine` field in @p aInfo is updated. + * @retval OT_ERROR_NOT_FOUND Reached the end and no more line to generate. + * + */ +otError otLogGenerateNextHexDumpLine(otLogHexDumpInfo *aInfo); + /** * @} * diff --git a/src/cli/cli.cpp b/src/cli/cli.cpp index 28a9ea1f304..845127a4a32 100644 --- a/src/cli/cli.cpp +++ b/src/cli/cli.cpp @@ -6239,70 +6239,19 @@ void Interpreter::HandleLinkPcapReceive(const otRadioFrame *aFrame, bool aIsTx, void Interpreter::HandleLinkPcapReceive(const otRadioFrame *aFrame, bool aIsTx) { - OT_UNUSED_VARIABLE(aIsTx); + otLogHexDumpInfo info; - OutputNewLine(); - - for (size_t i = 0; i < 44; i++) - { - OutputFormat("="); - } - - OutputFormat("[len = %3u]", aFrame->mLength); - - for (size_t i = 0; i < 28; i++) - { - OutputFormat("="); - } + info.mDataBytes = aFrame->mPsdu; + info.mDataLength = aFrame->mLength; + info.mTitle = (aIsTx) ? "TX" : "RX"; + info.mIterator = 0; OutputNewLine(); - for (size_t i = 0; i < aFrame->mLength; i += 16) + while (otLogGenerateNextHexDumpLine(&info) == OT_ERROR_NONE) { - OutputFormat("|"); - - for (size_t j = 0; j < 16; j++) - { - if (i + j < aFrame->mLength) - { - OutputFormat(" %02X", aFrame->mPsdu[i + j]); - } - else - { - OutputFormat(" .."); - } - } - - OutputFormat("|"); - - for (size_t j = 0; j < 16; j++) - { - if (i + j < aFrame->mLength) - { - if (31 < aFrame->mPsdu[i + j] && aFrame->mPsdu[i + j] < 127) - { - OutputFormat(" %c", aFrame->mPsdu[i + j]); - } - else - { - OutputFormat(" ?"); - } - } - else - { - OutputFormat(" ."); - } - } - - OutputLine("|"); - } - - for (size_t i = 0; i < 83; i++) - { - OutputFormat("-"); + OutputLine("%s", info.mLine); } - - OutputNewLine(); } #if OPENTHREAD_CONFIG_BORDER_ROUTER_ENABLE diff --git a/src/core/api/logging_api.cpp b/src/core/api/logging_api.cpp index 0245f5b8905..29343ed5926 100644 --- a/src/core/api/logging_api.cpp +++ b/src/core/api/logging_api.cpp @@ -232,3 +232,10 @@ void otLogCli(otLogLevel aLogLevel, const char *aFormat, ...) #endif return; } + +otError otLogGenerateNextHexDumpLine(otLogHexDumpInfo *aInfo) +{ + AssertPointerIsNotNull(aInfo); + + return GenerateNextHexDumpLine(*aInfo); +} diff --git a/src/core/common/log.cpp b/src/core/common/log.cpp index 04c74bbb2e8..cdf447e3a97 100644 --- a/src/core/common/log.cpp +++ b/src/core/common/log.cpp @@ -40,6 +40,7 @@ #include "common/code_utils.hpp" #include "common/instance.hpp" #include "common/num_utils.hpp" +#include "common/numeric_limits.hpp" #include "common/string.hpp" /* @@ -169,99 +170,120 @@ template void Logger::DumpAtLevel(const char *aModuleName, const void *aData, uint16_t aDataLength); -void Logger::DumpLine(const char *aModuleName, LogLevel aLogLevel, const uint8_t *aData, const uint16_t aDataLength) +void Logger::DumpInModule(const char *aModuleName, + LogLevel aLogLevel, + const char *aText, + const void *aData, + uint16_t aDataLength) { - ot::String string; + HexDumpInfo info; + + VerifyOrExit(otLoggingGetLevel() >= aLogLevel); - string.Append("|"); + info.mDataBytes = reinterpret_cast(aData); + info.mDataLength = aDataLength; + info.mTitle = aText; + info.mIterator = 0; - for (uint8_t i = 0; i < kDumpBytesPerLine; i++) + while (GenerateNextHexDumpLine(info) == kErrorNone) { - if (i < aDataLength) - { - string.Append(" %02X", aData[i]); - } - else - { - string.Append(" .."); - } + LogInModule(aModuleName, aLogLevel, "%s", info.mLine); + } - if (!((i + 1) % 8)) - { - string.Append(" |"); - } +exit: + return; +} + +#endif // OPENTHREAD_CONFIG_LOG_PKT_DUMP + +#endif // OT_SHOULD_LOG + +Error GenerateNextHexDumpLine(HexDumpInfo &aInfo) +{ + constexpr uint16_t kIterTableStartLine = 0; + constexpr uint16_t kIterFirstDataLine = NumericLimits::kMax - 2; + constexpr uint16_t kIterTableEndLine = NumericLimits::kMax - 1; + constexpr uint16_t kIterFinished = NumericLimits::kMax; + constexpr uint16_t kWidth = 72; + constexpr uint16_t kTitleSuffixLen = sizeof("[ len=000]") - 1; + constexpr uint16_t kDumpBytesPerLine = 16; + + Error error = kErrorNone; + StringWriter writer(aInfo.mLine, sizeof(aInfo.mLine)); + + switch (aInfo.mIterator) + { + case kIterTableStartLine: + { + uint16_t txtLen = StringLength(aInfo.mTitle, kWidth - kTitleSuffixLen) + kTitleSuffixLen; + + writer.AppendCharMultipleTimes('=', static_cast((kWidth - txtLen) / 2)); + writer.Append("[%s len=%03u]", aInfo.mTitle, aInfo.mDataLength); + writer.AppendCharMultipleTimes('=', static_cast(kWidth - txtLen - (kWidth - txtLen) / 2)); + aInfo.mIterator = kIterFirstDataLine; + break; } - string.Append(" "); + case kIterTableEndLine: + writer.AppendCharMultipleTimes('-', kWidth); + aInfo.mIterator = kIterFinished; + break; + + case kIterFinished: + error = kErrorNotFound; + break; - for (uint8_t i = 0; i < kDumpBytesPerLine; i++) + case kIterFirstDataLine: + aInfo.mIterator = 0; + OT_FALL_THROUGH; + + default: { - char c = '.'; + uint16_t startIndex = aInfo.mIterator; + uint16_t endIndex = aInfo.mIterator + kDumpBytesPerLine; + + writer.Append("|"); - if (i < aDataLength) + for (uint16_t i = startIndex; i < endIndex; i++) { - char byteAsChar = static_cast(0x7f & aData[i]); + (i < aInfo.mDataLength) ? writer.Append(" %02X", aInfo.mDataBytes[i]) : writer.Append(" "); - if (isprint(byteAsChar)) + if ((i % 8) == 7) { - c = byteAsChar; + writer.Append(" |"); } } - string.Append("%c", c); - } + writer.Append(" "); - LogInModule(aModuleName, aLogLevel, "%s", string.AsCString()); -} + for (uint16_t i = startIndex; i < endIndex; i++) + { + char c = ' '; -void Logger::DumpInModule(const char *aModuleName, - LogLevel aLogLevel, - const char *aText, - const void *aData, - uint16_t aDataLength) -{ - constexpr uint16_t kWidth = 72; - constexpr uint16_t kTextSuffixLen = sizeof("[ len=000]") - 1; + if (i < aInfo.mDataLength) + { + uint8_t byte = aInfo.mDataBytes[i]; - uint16_t txtLen = StringLength(aText, kWidth - kTextSuffixLen) + kTextSuffixLen; - ot::String string; + c = ((byte < 127) && isprint(static_cast(byte))) ? static_cast(byte) : '.'; + } - VerifyOrExit(otLoggingGetLevel() >= aLogLevel); + writer.Append("%c", c); + } - for (uint16_t i = 0; i < static_cast((kWidth - txtLen) / 2); i++) - { - string.Append("="); - } + writer.Append(" |"); - string.Append("[%s len=%03u]", aText, aDataLength); + aInfo.mIterator = endIndex; - for (uint16_t i = 0; i < static_cast(kWidth - txtLen - (kWidth - txtLen) / 2); i++) - { - string.Append("="); - } - - LogInModule(aModuleName, aLogLevel, "%s", string.AsCString()); + if (aInfo.mIterator >= aInfo.mDataLength) + { + aInfo.mIterator = kIterTableEndLine; + } - for (uint16_t i = 0; i < aDataLength; i += kDumpBytesPerLine) - { - DumpLine(aModuleName, aLogLevel, static_cast(aData) + i, - Min(static_cast(aDataLength - i), kDumpBytesPerLine)); + break; } - - string.Clear(); - - for (uint16_t i = 0; i < kWidth; i++) - { - string.Append("-"); } - LogInModule(aModuleName, aLogLevel, "%s", string.AsCString()); - -exit: - return; + return error; } -#endif // OPENTHREAD_CONFIG_LOG_PKT_DUMP - -#endif // OT_SHOULD_LOG } // namespace ot diff --git a/src/core/common/log.hpp b/src/core/common/log.hpp index 6d46030db71..47293e0b3b5 100644 --- a/src/core/common/log.hpp +++ b/src/core/common/log.hpp @@ -40,6 +40,8 @@ #include #include +#include "common/error.hpp" + namespace ot { /** @@ -332,8 +334,6 @@ class Logger template static void DumpAtLevel(const char *aModuleName, const char *aText, const void *aData, uint16_t aDataLength); - - static void DumpLine(const char *aModuleName, LogLevel aLogLevel, const uint8_t *aData, uint16_t aDataLength); #endif }; @@ -372,6 +372,32 @@ extern template void Logger::DumpAtLevel(const char *aModuleName, #endif // OPENTHREAD_CONFIG_LOG_PKT_DUMP #endif // OT_SHOULD_LOG +typedef otLogHexDumpInfo HexDumpInfo; ///< Represents the hex dump info. + +/** + * Generates the next hex dump line. + * + * Can call this method back-to-back to generate the hex dump output line by line. On the first call the `mIterator` + * field in @p aInfo MUST be set to zero. + * + * Here is an example of the generated hex dump output: + * + * "==========================[{mTitle} len=070]============================" + * "| 41 D8 87 34 12 FF FF 25 | 4C 57 DA F2 FB 2F 62 7F | A..4...%LW.../b. |" + * "| 3B 01 F0 4D 4C 4D 4C 54 | 4F 00 15 15 00 00 00 00 | ;..MLMLTO....... |" + * "| 00 00 00 01 80 DB 60 82 | 7E 33 72 3B CC B3 A1 84 | ......`.~3r;.... |" + * "| 3B E6 AD B2 0B 45 E7 45 | C5 B9 00 1A CB 2D 6D 1C | ;....E.E.....-m. |" + * "| 10 3E 3C F5 D3 70 | | .><..p |" + * "------------------------------------------------------------------------" + * + * @param[in,out] aInfo A reference to a `LogHexDumpInfo` to use to generate hex dump. + * + * @retval kErrorNone Successfully generated the next line, `mLine` field in @p aInfo is updated. + * @retval kErrorNotFound Reached the end and no more line to generate. + * + */ +Error GenerateNextHexDumpLine(HexDumpInfo &aInfo); + } // namespace ot #endif // LOG_HPP_ diff --git a/src/core/common/string.cpp b/src/core/common/string.cpp index fa0dc3e5da7..4019628d5f1 100644 --- a/src/core/common/string.cpp +++ b/src/core/common/string.cpp @@ -310,6 +310,16 @@ StringWriter &StringWriter::AppendHexBytes(const uint8_t *aBytes, uint16_t aLeng return *this; } +StringWriter &StringWriter::AppendCharMultipleTimes(char aChar, uint16_t aCount) +{ + while (aCount--) + { + Append("%c", aChar); + } + + return *this; +} + bool IsValidUtf8String(const char *aString) { return IsValidUtf8String(aString, strlen(aString)); } bool IsValidUtf8String(const char *aString, size_t aLength) diff --git a/src/core/common/string.hpp b/src/core/common/string.hpp index 7cb657cc9c9..0c73bb603ec 100644 --- a/src/core/common/string.hpp +++ b/src/core/common/string.hpp @@ -423,6 +423,15 @@ class StringWriter */ StringWriter &AppendHexBytes(const uint8_t *aBytes, uint16_t aLength); + /** + * Appends a given character a given number of times. + * + * @param[in] aChar The character to append. + * @param[in] aCount Number of times to append @p aChar. + * + */ + StringWriter &AppendCharMultipleTimes(char aChar, uint16_t aCount); + /** * Converts all uppercase letter characters in the string to lowercase. * diff --git a/tests/scripts/expect/cli-promiscuous.exp b/tests/scripts/expect/cli-promiscuous.exp index 228c21cf6c9..58a51e17b12 100755 --- a/tests/scripts/expect/cli-promiscuous.exp +++ b/tests/scripts/expect/cli-promiscuous.exp @@ -76,9 +76,8 @@ expect "16 bytes from $addr: icmp_seq=1" expect_line "Done" switch_node 3 -expect -re {============================================\[len = +\d+]============================} -expect -re {\|( ([0-9A-Z]{2}|\.\.)){16}\|( .){16}\|} -expect -- "-----------------------------------------------------------------------------------" +expect -re {==============================\[RX len=\d+\]==============================} +expect -- "------------------------------------------------------------------------" send "promiscuous disable\n" expect_line "Done" diff --git a/tests/toranj/openthread-core-toranj-config.h b/tests/toranj/openthread-core-toranj-config.h index 7e2d4c7d4b0..4b7ec74a213 100644 --- a/tests/toranj/openthread-core-toranj-config.h +++ b/tests/toranj/openthread-core-toranj-config.h @@ -111,7 +111,7 @@ #define OPENTHREAD_CONFIG_MAC_FILTER_SIZE 80 -#define OPENTHREAD_CONFIG_LOG_LEVEL OT_LOG_LEVEL_INFO +#define OPENTHREAD_CONFIG_LOG_LEVEL OT_LOG_LEVEL_DEBG #define OPENTHREAD_CONFIG_LOG_LEVEL_DYNAMIC_ENABLE 1