From 420813e03d4690ed8c99daeb4b5970a0cffa6ea5 Mon Sep 17 00:00:00 2001 From: Abtin Keshavarzian Date: Wed, 23 May 2018 00:43:09 -0700 Subject: [PATCH] [ncp] adding new log output through NCP spinel property (#2722) This commit adds a new log output model for NCP to use a newly added spinel stream log property. `OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL` can be used to be select the new log output model. This commit defines a new spinel property `SPINEL_PROP_STREAM_LOG` which provides streaming of formatted log string from NCP along with an optional metadata structure. OpenThread log level and log region are included as part of the metadata. This commit also updates the `toranj` configuration header file to use the new log output model. --- examples/apps/ncp/main.c | 5 - examples/platforms/cc2538/logging.c | 5 +- examples/platforms/cc2650/logging.c | 5 +- examples/platforms/cc2652/logging.c | 5 +- examples/platforms/da15000/logging.c | 5 +- examples/platforms/efr32/logging.c | 5 +- examples/platforms/emsk/logging.c | 5 +- examples/platforms/gp712/logging.c | 5 +- examples/platforms/kw41z/logging.c | 5 +- examples/platforms/nrf52840/logging.c | 5 +- examples/platforms/nrf52840/platform.c | 6 +- examples/platforms/posix/logging.c | 5 +- examples/platforms/samr21/logging.c | 5 +- src/core/openthread-core-default-config.h | 2 + src/ncp/ncp_base.cpp | 188 ++++++++++++++++--- src/ncp/ncp_base.hpp | 13 ++ src/ncp/spinel.c | 8 + src/ncp/spinel.h | 46 +++++ tests/toranj/openthread-core-toranj-config.h | 20 +- 19 files changed, 286 insertions(+), 57 deletions(-) diff --git a/examples/apps/ncp/main.c b/examples/apps/ncp/main.c index 6f33a3ad0..c68010ad4 100644 --- a/examples/apps/ncp/main.c +++ b/examples/apps/ncp/main.c @@ -103,16 +103,11 @@ pseudo_reset: return 0; } - /* - * Provide, if required an "otPlatLog()" function - */ - #if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_APP) void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { OT_UNUSED_VARIABLE(aLogLevel); OT_UNUSED_VARIABLE(aLogRegion); - OT_UNUSED_VARIABLE(aFormat); va_list ap; va_start(ap, aFormat); diff --git a/examples/platforms/cc2538/logging.c b/examples/platforms/cc2538/logging.c index 0cbb7792f..190a4bfa1 100644 --- a/examples/platforms/cc2538/logging.c +++ b/examples/platforms/cc2538/logging.c @@ -35,8 +35,9 @@ #include #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogLevel; (void)aLogRegion; diff --git a/examples/platforms/cc2650/logging.c b/examples/platforms/cc2650/logging.c index 0cbb7792f..190a4bfa1 100644 --- a/examples/platforms/cc2650/logging.c +++ b/examples/platforms/cc2650/logging.c @@ -35,8 +35,9 @@ #include #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogLevel; (void)aLogRegion; diff --git a/examples/platforms/cc2652/logging.c b/examples/platforms/cc2652/logging.c index 0cbb7792f..190a4bfa1 100644 --- a/examples/platforms/cc2652/logging.c +++ b/examples/platforms/cc2652/logging.c @@ -35,8 +35,9 @@ #include #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogLevel; (void)aLogRegion; diff --git a/examples/platforms/da15000/logging.c b/examples/platforms/da15000/logging.c index 8b042d983..81cfaac2c 100644 --- a/examples/platforms/da15000/logging.c +++ b/examples/platforms/da15000/logging.c @@ -34,8 +34,9 @@ #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogLevel; (void)aLogRegion; diff --git a/examples/platforms/efr32/logging.c b/examples/platforms/efr32/logging.c index eb8a6e47a..dbb2b43e4 100644 --- a/examples/platforms/efr32/logging.c +++ b/examples/platforms/efr32/logging.c @@ -36,8 +36,9 @@ #include #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogLevel; (void)aLogRegion; diff --git a/examples/platforms/emsk/logging.c b/examples/platforms/emsk/logging.c index 0d4dba83f..8aafa0548 100644 --- a/examples/platforms/emsk/logging.c +++ b/examples/platforms/emsk/logging.c @@ -36,8 +36,9 @@ #include #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogLevel; (void)aLogRegion; diff --git a/examples/platforms/gp712/logging.c b/examples/platforms/gp712/logging.c index 3ebdbef91..7c6fff125 100644 --- a/examples/platforms/gp712/logging.c +++ b/examples/platforms/gp712/logging.c @@ -53,7 +53,8 @@ offset += (unsigned int)charsWritten; \ otEXPECT_ACTION(offset < sizeof(logString), logString[sizeof(logString) - 1] = 0) -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) int PlatOtLogLevelToSysLogLevel(otLogLevel aLogLevel) { @@ -88,7 +89,7 @@ int PlatOtLogLevelToSysLogLevel(otLogLevel aLogLevel) return sysloglevel; } -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { char logString[512]; unsigned int offset; diff --git a/examples/platforms/kw41z/logging.c b/examples/platforms/kw41z/logging.c index eb8a6e47a..dbb2b43e4 100644 --- a/examples/platforms/kw41z/logging.c +++ b/examples/platforms/kw41z/logging.c @@ -36,8 +36,9 @@ #include #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogLevel; (void)aLogRegion; diff --git a/examples/platforms/nrf52840/logging.c b/examples/platforms/nrf52840/logging.c index b9682d325..be8486ab9 100644 --- a/examples/platforms/nrf52840/logging.c +++ b/examples/platforms/nrf52840/logging.c @@ -48,7 +48,8 @@ #include #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) #include #if (LOG_RTT_COLOR_ENABLE == 1) @@ -140,7 +141,7 @@ void nrf5LogDeinit() sLogInitialized = false; } -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogRegion; diff --git a/examples/platforms/nrf52840/platform.c b/examples/platforms/nrf52840/platform.c index 9e23d30d6..9bbc38513 100644 --- a/examples/platforms/nrf52840/platform.c +++ b/examples/platforms/nrf52840/platform.c @@ -73,7 +73,8 @@ void PlatformInit(int argc, char *argv[]) nrf_drv_clock_init(); -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) nrf5LogInit(); #endif nrf5AlarmInit(); @@ -100,7 +101,8 @@ void PlatformDeinit(void) nrf5UartDeinit(); nrf5RandomDeinit(); nrf5AlarmDeinit(); -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) nrf5LogDeinit(); #endif } diff --git a/examples/platforms/posix/logging.c b/examples/platforms/posix/logging.c index dad702e99..5bfffcffe 100644 --- a/examples/platforms/posix/logging.c +++ b/examples/platforms/posix/logging.c @@ -53,8 +53,9 @@ offset += (unsigned int)charsWritten; \ otEXPECT_ACTION(offset < sizeof(logString), logString[sizeof(logString) - 1] = 0) -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { char logString[512]; unsigned int offset; diff --git a/examples/platforms/samr21/logging.c b/examples/platforms/samr21/logging.c index 0cbb7792f..190a4bfa1 100644 --- a/examples/platforms/samr21/logging.c +++ b/examples/platforms/samr21/logging.c @@ -35,8 +35,9 @@ #include #include -#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) -void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED) || \ + (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) +OT_TOOL_WEAK void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) { (void)aLogLevel; (void)aLogRegion; diff --git a/src/core/openthread-core-default-config.h b/src/core/openthread-core-default-config.h index 409353435..d2b53d54f 100644 --- a/src/core/openthread-core-default-config.h +++ b/src/core/openthread-core-default-config.h @@ -597,6 +597,8 @@ #define OPENTHREAD_CONFIG_LOG_OUTPUT_APP 2 /** Log output is handled by a platform defined function */ #define OPENTHREAD_CONFIG_LOG_OUTPUT_PLATFORM_DEFINED 3 +/** Log output for NCP goes to Spinel `STREAM_LOG` property (for CLI platform defined function is expected) */ +#define OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL 4 /** * @def OPENTHREAD_CONFIG_LOG_LEVEL diff --git a/src/ncp/ncp_base.cpp b/src/ncp/ncp_base.cpp index e1b65339b..ace60c99b 100644 --- a/src/ncp/ncp_base.cpp +++ b/src/ncp/ncp_base.cpp @@ -824,6 +824,140 @@ exit: return error; } +uint8_t NcpBase::ConvertLogLevel(otLogLevel aLogLevel) +{ + uint8_t spinelLogLevel = SPINEL_NCP_LOG_LEVEL_EMERG; + + switch (aLogLevel) + { + case OT_LOG_LEVEL_NONE: + spinelLogLevel = SPINEL_NCP_LOG_LEVEL_EMERG; + break; + + case OT_LOG_LEVEL_CRIT: + spinelLogLevel = SPINEL_NCP_LOG_LEVEL_CRIT; + break; + + case OT_LOG_LEVEL_WARN: + spinelLogLevel = SPINEL_NCP_LOG_LEVEL_WARN; + break; + + case OT_LOG_LEVEL_INFO: + spinelLogLevel = SPINEL_NCP_LOG_LEVEL_INFO; + break; + + case OT_LOG_LEVEL_DEBG: + spinelLogLevel = SPINEL_NCP_LOG_LEVEL_DEBUG; + break; + } + + return spinelLogLevel; +} + +unsigned int NcpBase::ConvertLogRegion(otLogRegion aLogRegion) +{ + unsigned int spinelLogRegion = SPINEL_NCP_LOG_REGION_NONE; + + switch (aLogRegion) + { + + case OT_LOG_REGION_API: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_API; + break; + + case OT_LOG_REGION_MLE: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_MLE; + break; + + case OT_LOG_REGION_ARP: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_ARP; + break; + + case OT_LOG_REGION_NET_DATA: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_NET_DATA; + break; + + case OT_LOG_REGION_ICMP: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_ICMP; + break; + + case OT_LOG_REGION_IP6: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_IP6; + break; + + case OT_LOG_REGION_MAC: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_MAC; + break; + + case OT_LOG_REGION_MEM: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_MEM; + break; + + case OT_LOG_REGION_NCP: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_NCP; + break; + + case OT_LOG_REGION_MESH_COP: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_MESH_COP; + break; + + case OT_LOG_REGION_NET_DIAG: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_NET_DIAG; + break; + + case OT_LOG_REGION_PLATFORM: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_PLATFORM; + break; + + case OT_LOG_REGION_COAP: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_COAP; + break; + + case OT_LOG_REGION_CLI: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_CLI; + break; + + case OT_LOG_REGION_CORE: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_CORE; + break; + + case OT_LOG_REGION_UTIL: + spinelLogRegion = SPINEL_NCP_LOG_REGION_OT_UTIL; + break; + } + + return spinelLogRegion; +} + +void NcpBase::Log(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aLogString) +{ + otError error = OT_ERROR_NONE; + uint8_t header = SPINEL_HEADER_FLAG | SPINEL_HEADER_IID_0; + + VerifyOrExit(!mDisableStreamWrite); + VerifyOrExit(!mChangedPropsSet.IsPropertyFiltered(SPINEL_PROP_STREAM_LOG)); + + // If there is a pending queued response we do not allow any new log + // stream writes. This is to ensure that log messages can not continue + // to use the NCP buffer space and block other spinel frames. + + VerifyOrExit(IsResponseQueueEmpty(), error = OT_ERROR_NO_BUFS); + + SuccessOrExit(error = mEncoder.BeginFrame(header, SPINEL_CMD_PROP_VALUE_IS, SPINEL_PROP_STREAM_LOG)); + SuccessOrExit(error = mEncoder.WriteUtf8(aLogString)); + SuccessOrExit(error = mEncoder.WriteUint8(ConvertLogLevel(aLogLevel))); + SuccessOrExit(error = mEncoder.WriteUintPacked(ConvertLogRegion(aLogRegion))); + SuccessOrExit(error = mEncoder.EndFrame()); + +exit: + + if (error == OT_ERROR_NO_BUFS) + { + mChangedPropsSet.AddLastStatus(SPINEL_STATUS_NOMEM); + mUpdateChangedPropsTask.Post(); + } +} + #if OPENTHREAD_CONFIG_NCP_ENABLE_PEEK_POKE void NcpBase::RegisterPeekPokeDelagates(otNcpDelegateAllowPeekPoke aAllowPeekDelegate, @@ -1830,6 +1964,10 @@ otError NcpBase::GetPropertyHandler_CAPS(void) SuccessOrExit(error = mEncoder.WriteUintPacked(SPINEL_CAP_MAC_RAW)); #endif +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) + SuccessOrExit(error = mEncoder.WriteUintPacked(SPINEL_CAP_OPENTHREAD_LOG_METADATA)); +#endif + #if OPENTHREAD_MTD || OPENTHREAD_FTD SuccessOrExit(error = mEncoder.WriteUintPacked(SPINEL_CAP_NET_THREAD_1_0)); @@ -2169,32 +2307,7 @@ otError NcpBase::GetPropertyHandler_DEBUG_TEST_WATCHDOG(void) otError NcpBase::GetPropertyHandler_DEBUG_NCP_LOG_LEVEL(void) { - uint8_t logLevel = 0; - - switch (otGetDynamicLogLevel(mInstance)) - { - case OT_LOG_LEVEL_NONE: - logLevel = SPINEL_NCP_LOG_LEVEL_EMERG; - break; - - case OT_LOG_LEVEL_CRIT: - logLevel = SPINEL_NCP_LOG_LEVEL_CRIT; - break; - - case OT_LOG_LEVEL_WARN: - logLevel = SPINEL_NCP_LOG_LEVEL_WARN; - break; - - case OT_LOG_LEVEL_INFO: - logLevel = SPINEL_NCP_LOG_LEVEL_INFO; - break; - - case OT_LOG_LEVEL_DEBG: - logLevel = SPINEL_NCP_LOG_LEVEL_DEBUG; - break; - } - - return mEncoder.WriteUint8(logLevel); + return mEncoder.WriteUint8(ConvertLogLevel(otGetDynamicLogLevel(mInstance))); } otError NcpBase::SetPropertyHandler_DEBUG_NCP_LOG_LEVEL(void) @@ -2306,3 +2419,26 @@ extern "C" void otNcpPlatLogv(otLogLevel aLogLevel, otLogRegion aLogRegion, cons OT_UNUSED_VARIABLE(aLogLevel); OT_UNUSED_VARIABLE(aLogRegion); } + +#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) + +extern "C" void otPlatLog(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aFormat, ...) +{ + va_list args; + char logString[OPENTHREAD_CONFIG_NCP_SPINEL_LOG_MAX_SIZE]; + ot::Ncp::NcpBase *ncp = ot::Ncp::NcpBase::GetNcpInstance(); + + va_start(args, aFormat); + + if (vsnprintf(logString, sizeof(logString), aFormat, args) > 0) + { + if (ncp != NULL) + { + ncp->Log(aLogLevel, aLogRegion, logString); + } + } + + va_end(args); +} + +#endif // (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL) diff --git a/src/ncp/ncp_base.hpp b/src/ncp/ncp_base.hpp index 667b2d8b7..cbcf89dd5 100644 --- a/src/ncp/ncp_base.hpp +++ b/src/ncp/ncp_base.hpp @@ -102,6 +102,17 @@ public: */ otError StreamWrite(int aStreamId, const uint8_t *aDataPtr, int aDataLen); + /** + * This method send an OpenThread log message to host via `SPINEL_PROP_STREAM_LOG` property. + * + * @param[in] aLogLevel The log level + * @param[in] aLogRegion The log region + * @param[in] aLogString The log string + * + */ + void Log(otLogLevel aLogLevel, otLogRegion aLogRegion, const char *aLogString); + + #if OPENTHREAD_CONFIG_NCP_ENABLE_PEEK_POKE /** * This method registers peek/poke delegate functions with NCP module. @@ -709,6 +720,8 @@ protected: void StopLegacy(void) { } #endif + static uint8_t ConvertLogLevel(otLogLevel aLogLevel); + static unsigned int ConvertLogRegion(otLogRegion aLogRegion); protected: static NcpBase *sNcpInstance; diff --git a/src/ncp/spinel.c b/src/ncp/spinel.c index 79f7b335d..dedfae07e 100644 --- a/src/ncp/spinel.c +++ b/src/ncp/spinel.c @@ -1593,6 +1593,10 @@ spinel_prop_key_to_cstr(spinel_prop_key_t prop_key) ret = "PROP_STREAM_NET_INSECURE"; break; + case SPINEL_PROP_STREAM_LOG: + ret = "PROP_STREAM_LOG"; + break; + case SPINEL_PROP_CHANNEL_MANAGER_NEW_CHANNEL: ret = "PROP_CHANNEL_MANAGER_NEW_CHANNEL"; break; @@ -2202,6 +2206,10 @@ const char *spinel_capability_to_cstr(unsigned int capability) ret = "CAP_CHANNEL_MANAGER"; break; + case SPINEL_CAP_OPENTHREAD_LOG_METADATA: + ret = "CAP_OPENTHREAD_LOG_METADATA"; + break; + case SPINEL_CAP_ERROR_RATE_TRACKING: ret = "CAP_ERROR_RATE_TRACKING"; break; diff --git a/src/ncp/spinel.h b/src/ncp/spinel.h index 7abfd6246..423aa9588 100644 --- a/src/ncp/spinel.h +++ b/src/ncp/spinel.h @@ -311,6 +311,27 @@ enum SPINEL_NCP_LOG_LEVEL_DEBUG = 7, }; +enum +{ + SPINEL_NCP_LOG_REGION_NONE = 0, + SPINEL_NCP_LOG_REGION_OT_API = 1, + SPINEL_NCP_LOG_REGION_OT_MLE = 2, + SPINEL_NCP_LOG_REGION_OT_ARP = 3, + SPINEL_NCP_LOG_REGION_OT_NET_DATA = 4, + SPINEL_NCP_LOG_REGION_OT_ICMP = 5, + SPINEL_NCP_LOG_REGION_OT_IP6 = 6, + SPINEL_NCP_LOG_REGION_OT_MAC = 7, + SPINEL_NCP_LOG_REGION_OT_MEM = 8, + SPINEL_NCP_LOG_REGION_OT_NCP = 9, + SPINEL_NCP_LOG_REGION_OT_MESH_COP = 10, + SPINEL_NCP_LOG_REGION_OT_NET_DIAG = 11, + SPINEL_NCP_LOG_REGION_OT_PLATFORM = 12, + SPINEL_NCP_LOG_REGION_OT_COAP = 13, + SPINEL_NCP_LOG_REGION_OT_CLI = 14, + SPINEL_NCP_LOG_REGION_OT_CORE = 15, + SPINEL_NCP_LOG_REGION_OT_UTIL = 16, +}; + typedef struct { uint8_t bytes[8]; @@ -439,6 +460,7 @@ enum SPINEL_CAP_CHANNEL_MONITOR = (SPINEL_CAP_OPENTHREAD__BEGIN + 3), SPINEL_CAP_ERROR_RATE_TRACKING = (SPINEL_CAP_OPENTHREAD__BEGIN + 4), SPINEL_CAP_CHANNEL_MANAGER = (SPINEL_CAP_OPENTHREAD__BEGIN + 5), + SPINEL_CAP_OPENTHREAD_LOG_METADATA = (SPINEL_CAP_OPENTHREAD__BEGIN + 6), SPINEL_CAP_OPENTHREAD__END = 640, SPINEL_CAP_THREAD__BEGIN = 1024, @@ -1453,6 +1475,30 @@ typedef enum SPINEL_PROP_STREAM_RAW = SPINEL_PROP_STREAM__BEGIN + 1, ///< [dD] SPINEL_PROP_STREAM_NET = SPINEL_PROP_STREAM__BEGIN + 2, ///< [dD] SPINEL_PROP_STREAM_NET_INSECURE = SPINEL_PROP_STREAM__BEGIN + 3, ///< [dD] + + /// Log Stream + /** Format: `UD` (stream, read only) + * + * This property is a read-only streaming property which provides + * formatted log string from NCP. This property provides asynchronous + * `CMD_PROP_VALUE_IS` updates with a new log string and includes + * optional meta data. + * + * `U`: The log string + * `D`: Log metadata (optional). + * + * Any data after the log string is considered metadata and is OPTIONAL. + * Pretense of `SPINEL_CAP_OPENTHREAD_LOG_METADATA` capability + * indicates that OpenThread log metadata format is used as defined + * below: + * + * `C`: Log level (as per definition in enumeration + * `SPINEL_NCP_LOG_LEVEL_`) + * `i`: OpenThread Log region (as per definition in enumeration + * `SPINEL_NCP_LOG_REGION_). + * + */ + SPINEL_PROP_STREAM_LOG = SPINEL_PROP_STREAM__BEGIN + 4, SPINEL_PROP_STREAM__END = 0x80, SPINEL_PROP_OPENTHREAD__BEGIN = 0x1900, diff --git a/tests/toranj/openthread-core-toranj-config.h b/tests/toranj/openthread-core-toranj-config.h index 9e78dc6a1..07fa42d58 100644 --- a/tests/toranj/openthread-core-toranj-config.h +++ b/tests/toranj/openthread-core-toranj-config.h @@ -122,7 +122,7 @@ * Selects if, and where the LOG output goes to. * */ -#define OPENTHREAD_CONFIG_LOG_OUTPUT OPENTHREAD_CONFIG_LOG_OUTPUT_APP +#define OPENTHREAD_CONFIG_LOG_OUTPUT OPENTHREAD_CONFIG_LOG_OUTPUT_NCP_SPINEL /** * @def OPENTHREAD_CONFIG_LOG_LEVEL @@ -140,13 +140,29 @@ */ #define OPENTHREAD_CONFIG_ENABLE_DYNAMIC_LOG_LEVEL 1 +/** + * @def OPENTHREAD_CONFIG_LOG_PREPEND_LEVEL + * + * Define to prepend the log level to all log messages + * + */ +#define OPENTHREAD_CONFIG_LOG_PREPEND_LEVEL 0 + +/** + * @def OPENTHREAD_CONFIG_LOG_PREPEND_REGION + * + * Define to prepend the log region to all log messages + * + */ +#define OPENTHREAD_CONFIG_LOG_PREPEND_REGION 0 + /** * @def OPENTHREAD_CONFIG_LOG_SUFFIX * * Define suffix to append at the end of logs. * */ -#define OPENTHREAD_CONFIG_LOG_SUFFIX "\n" +#define OPENTHREAD_CONFIG_LOG_SUFFIX "" /** * @def OPENTHREAD_CONFIG_NCP_TX_BUFFER_SIZE