diff --git a/examples/apps/cli/cli_uart.cpp b/examples/apps/cli/cli_uart.cpp index b2d271dcc..38fb838b7 100644 --- a/examples/apps/cli/cli_uart.cpp +++ b/examples/apps/cli/cli_uart.cpp @@ -199,34 +199,6 @@ static otError ProcessCommand(void) sRxBuffer[--sRxLength] = '\0'; } -#if OPENTHREAD_CONFIG_LOG_OUTPUT != OPENTHREAD_CONFIG_LOG_OUTPUT_NONE - /* - * Note this is here for this reason: - * - * TEXT (command) input ... in a test automation script occurs - * rapidly and often without gaps between the command and the - * terminal CR - * - * In contrast as a human is typing there is a delay between the - * last character of a command and the terminal CR which executes - * a command. - * - * During that human induced delay a tasklet may be scheduled and - * the LOG becomes confusing and it is hard to determine when - * something happened. Which happened first? the command-CR or - * the tasklet. - * - * Yes, while rare it is a race condition that is hard to debug. - * - * Thus this is here to affirmatively LOG exactly when the CLI - * command is being executed. - */ -#if OPENTHREAD_CONFIG_MULTIPLE_INSTANCE_ENABLE - /* TODO: how exactly do we get the instance here? */ -#else - otLogInfoCli("execute command: %s", sRxBuffer); -#endif -#endif if (sRxLength > 0) { otCliInputLine(sRxBuffer); diff --git a/src/cli/cli.cpp b/src/cli/cli.cpp index 03f9b3d5a..ac54cb362 100644 --- a/src/cli/cli.cpp +++ b/src/cli/cli.cpp @@ -82,6 +82,7 @@ #include #endif +#include "common/logging.hpp" #include "common/new.hpp" #include "common/string.hpp" #include "mac/channel_mask.hpp" @@ -127,6 +128,10 @@ Interpreter::Interpreter(Instance *aInstance, otCliOutputCallback aCallback, voi #if OPENTHREAD_CONFIG_SRP_SERVER_ENABLE , mSrpServer(*this) #endif +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + , mOutputLength(0) + , mIsLogging(false) +#endif { #if OPENTHREAD_FTD otThreadSetDiscoveryRequestCallback(mInstance, &Interpreter::HandleDiscoveryRequest, this); @@ -4551,6 +4556,10 @@ void Interpreter::ProcessLine(char *aBuf) VerifyOrExit(StringLength(aBuf, kMaxLineLength) <= kMaxLineLength - 1, error = OT_ERROR_PARSE); +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + otLogNoteCli("Input: %s", aBuf); +#endif + error = Utils::CmdLineParser::ParseCmd(aBuf, args); if (error != OT_ERROR_NONE) @@ -4918,7 +4927,98 @@ void Interpreter::OutputSpaces(uint8_t aCount) int Interpreter::OutputFormatV(const char *aFormat, va_list aArguments) { - return mOutputCallback(mOutputContext, aFormat, aArguments); + int rval; +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + va_list args; + int charsWritten; + bool truncated = false; + + va_copy(args, aArguments); +#endif + + rval = mOutputCallback(mOutputContext, aFormat, aArguments); + +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + VerifyOrExit(!IsLogging()); + + charsWritten = vsnprintf(&mOutputString[mOutputLength], sizeof(mOutputString) - mOutputLength, aFormat, args); + + VerifyOrExit(charsWritten >= 0, mOutputLength = 0); + + if (static_cast(charsWritten) >= sizeof(mOutputString) - mOutputLength) + { + truncated = true; + mOutputLength = sizeof(mOutputString) - 1; + } + else + { + mOutputLength += charsWritten; + } + + while (true) + { + char *lineEnd = strchr(mOutputString, '\r'); + + if (lineEnd == nullptr) + { + break; + } + + *lineEnd = '\0'; + + if (lineEnd > mOutputString) + { + otLogNoteCli("Output: %s", mOutputString); + } + + lineEnd++; + + while ((*lineEnd == '\n') || (*lineEnd == '\r')) + { + lineEnd++; + } + + // Example of the pointers and lengths. + // + // - mOutputString = "hi\r\nmore" + // - mOutputLength = 8 + // - lineEnd = &mOutputString[4] + // + // + // 0 1 2 3 4 5 6 7 8 9 + // +----+----+----+----+----+----+----+----+----+--- + // | h | i | \r | \n | m | o | r | e | \0 | + // +----+----+----+----+----+----+----+----+----+--- + // ^ ^ + // | | + // lineEnd mOutputString[mOutputLength] + // + // + // New length is `&mOutputString[8] - &mOutputString[4] -> 4`. + // + // We move (newLen + 1 = 5) chars from `lineEnd` to start of + // `mOutputString` which will include the `\0` char. + // + // If `lineEnd` and `mOutputString[mOutputLength]` are the same + // the code works correctly as well (new length set to zero and + // the `\0` is copied). + + mOutputLength = static_cast(&mOutputString[mOutputLength] - lineEnd); + memmove(mOutputString, lineEnd, mOutputLength + 1); + } + + if (truncated) + { + otLogNoteCli("Output: %s ...", mOutputString); + mOutputLength = 0; + } + +exit: + va_end(args); + +#endif // OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + + return rval; } void Interpreter::Initialize(otInstance *aInstance, otCliOutputCallback aCallback, void *aContext) @@ -4968,8 +5068,20 @@ extern "C" void otCliPlatLogv(otLogLevel aLogLevel, otLogRegion aLogRegion, cons VerifyOrExit(Interpreter::IsInitialized()); +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + // CLI output can be used for logging. The `IsLogging` flag is + // used to indicate whether it is being used for a CLI command + // output or for logging. + Interpreter::GetInterpreter().SetIsLogging(true); +#endif + Interpreter::GetInterpreter().OutputFormatV(aFormat, aArgs); Interpreter::GetInterpreter().OutputLine(""); + +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + Interpreter::GetInterpreter().SetIsLogging(false); +#endif + exit: return; } @@ -4980,8 +5092,17 @@ extern "C" void otCliPlatLogLine(otLogLevel aLogLevel, otLogRegion aLogRegion, c OT_UNUSED_VARIABLE(aLogRegion); VerifyOrExit(Interpreter::IsInitialized()); + +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + Interpreter::GetInterpreter().SetIsLogging(true); +#endif + Interpreter::GetInterpreter().OutputLine(aLogLine); +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + Interpreter::GetInterpreter().SetIsLogging(false); +#endif + exit: return; } diff --git a/src/cli/cli.hpp b/src/cli/cli.hpp index 9042dc122..47fe7e006 100644 --- a/src/cli/cli.hpp +++ b/src/cli/cli.hpp @@ -87,6 +87,9 @@ namespace ot { */ namespace Cli { +extern "C" void otCliPlatLogv(otLogLevel, otLogRegion, const char *, va_list); +extern "C" void otCliPlatLogLine(otLogLevel, otLogRegion, const char *); + /** * This class implements the CLI interpreter. * @@ -103,6 +106,8 @@ class Interpreter friend class SrpServer; friend class TcpExample; friend class UdpExample; + friend void otCliPlatLogv(otLogLevel, otLogRegion, const char *, va_list); + friend void otCliPlatLogLine(otLogLevel, otLogRegion, const char *); public: typedef Utils::CmdLineParser::Arg Arg; @@ -721,6 +726,11 @@ private: } void HandleDiscoveryRequest(const otThreadDiscoveryRequestInfo &aInfo); +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + bool IsLogging(void) const { return mIsLogging; } + void SetIsLogging(bool aIsLogging) { mIsLogging = aIsLogging; } +#endif + static constexpr Command sCommands[] = { #if OPENTHREAD_CONFIG_BORDER_AGENT_ENABLE {"ba", &Interpreter::ProcessBorderAgent}, @@ -937,6 +947,12 @@ private: #if OPENTHREAD_CONFIG_SRP_SERVER_ENABLE SrpServer mSrpServer; #endif + +#if OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + char mOutputString[OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_LOG_STRING_SIZE]; + uint16_t mOutputLength; + bool mIsLogging; +#endif }; // Specializations of `FormatStringFor()` diff --git a/src/cli/cli_config.h b/src/cli/cli_config.h index e8d6758bb..edebf7feb 100644 --- a/src/cli/cli_config.h +++ b/src/cli/cli_config.h @@ -59,6 +59,7 @@ #endif /** +<<<<<<< HEAD * @def OPENTHREAD_CONFIG_CLI_TCP_ENABLE * * Indicates whether TCP should be enabled in the CLI tool. @@ -87,4 +88,30 @@ #define OPENTHREAD_CONFIG_CLI_TCP_RECEIVE_BUFFER_SIZE OT_TCP_RECEIVE_BUFFER_SIZE_FEW_HOPS #endif +/** + * @def OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE + * + * Define as 1 for CLI to emit its command input string and the resulting output to the logs. + * + * By default this is enabled on any POSIX based platform (`OPENTHREAD_POSIX`) and only when CLI itself is not being + * used for logging. + * + */ +#ifndef OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE +#define OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE \ + (OPENTHREAD_POSIX && (OPENTHREAD_CONFIG_LOG_OUTPUT != OPENTHREAD_CONFIG_LOG_OUTPUT_APP)) +#endif + +/** + * @def OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_LOG_STRING_SIZE + * + * The log string buffer size (in bytes). + * + * This is only used when `OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_ENABLE` is enabled. + * + */ +#ifndef OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_LOG_STRING_SIZE +#define OPENTHREAD_CONFIG_CLI_LOG_INPUT_OUTPUT_LOG_STRING_SIZE OPENTHREAD_CONFIG_CLI_MAX_LINE_LENGTH +#endif + #endif // CONFIG_CLI_H_