[logging] dynamic level enhancements (#4809)

* Add cli command to get/set log level
* Add cmake option to enable dynamic log level
* Aggregate logfilename as sub-command of `log` command
* Add log level test
* Update readme

.github/workflows/simulation.yml

@@ -142,6 +142,17 @@ jobs:
     - name: Codecov
       uses: codecov/codecov-action@v1
 
+  expects:
+    runs-on: ubuntu-18.04
+    steps:
+    - uses: actions/checkout@v2
+    - name: Run
+      run: |
+        sudo apt --no-install-recommends install -y expect ninja-build
+        ./script/test build expect
+    - name: Codecov
+      uses: codecov/codecov-action@v1
+
   ncp:
     runs-on: ubuntu-18.04
     env:

etc/cmake/options.cmake

@@ -144,6 +144,11 @@ if(OT_LINK_RAW)
     list(APPEND OT_PRIVATE_DEFINES "OPENTHREAD_CONFIG_LINK_RAW_ENABLE=1")
 endif()
 
+option(OT_LOG_LEVEL_DYNAMIC "enable dynamic log level control")
+if(OT_LOG_LEVEL_DYNAMIC)
+    list(APPEND OT_PRIVATE_DEFINES "OPENTHREAD_CONFIG_LOG_LEVEL_DYNAMIC_ENABLE=1")
+endif()
+
 option(OT_MAC_FILTER "enable mac filter support")
 if(OT_MAC_FILTER)
     list(APPEND OT_PRIVATE_DEFINES "OPENTHREAD_CONFIG_MAC_FILTER_ENABLE=1")

include/openthread/logging.h

@@ -70,8 +70,11 @@ otLogLevel otLoggingGetLevel(void);
  *
  * @param[in]  aLogLevel               The log level.
  *
+ * @retval OT_ERROR_NONE            Successfully updated log level.
+ * @retval OT_ERROR_INVALID_ARGS    Log level value is invalid.
+ *
  */
-void otLoggingSetLevel(otLogLevel aLogLevel);
+otError otLoggingSetLevel(otLogLevel aLogLevel);
 
 /**
  * @}

script/test

@@ -51,6 +51,7 @@ readonly OT_TEST_COMMON_OPTIONS=(
     "-DOT_IP6_FRAGM=ON"
     "-DOT_JAM_DETECTION=ON"
     "-DOT_JOINER=ON"
+    "-DOT_LOG_LEVEL_DYNAMIC=ON"
     "-DOT_MAC_FILTER=ON"
     "-DOT_REFERENCE_DEVICE=ON"
     "-DOT_SERVICE=ON"
@@ -193,7 +194,7 @@ do_cert_suite() {
     [[ ! -f fail.log ]] || rm fail.log
 
     for test_case in "$@"; do
-        [[ ! -d tmp ]] || rm -rf tmp
+        rm -rf tmp
         if "${test_case}" &> test.log; then
             echo -e "${COLOR_PASS}PASS${COLOR_NONE} ${test_case}"
             pass_count=$(( pass_count + 1 ))
@@ -224,6 +225,35 @@ do_cert_suite() {
     fi
 }
 
+do_expect()
+{
+    local ot_command
+
+    if [[ "${NODE_MODE}" == rcp ]]; then
+        ot_command="${OT_CLI_PATH} ${RADIO_DEVICE}"
+    else
+        ot_command="${OT_BUILDDIR}/cmake/openthread-simulation-${THREAD_VERSION}/examples/apps/cli/ot-cli-ftd"
+    fi
+
+    while read -r script; do
+        rm -rf tmp
+        OT_COMMAND="${ot_command}" "${script}" || {
+            local exit_code=$?
+            echo -e "${COLOR_FAIL}FAIL${COLOR_NONE} ${script}"
+            exit "${exit_code}"
+        }
+        echo -e "${COLOR_PASS}PASS${COLOR_NONE} ${script}"
+    done < <(
+        if [[ $# != 0 ]]; then
+            for script in "$@"; do echo ${script}; done
+        else
+            find tests/scripts/expect -type f -executable
+        fi
+    )
+
+    exit 0
+}
+
 print_usage() {
     echo "USAGE: [ENVIRONMENTS] $0 COMMANDS
 
@@ -239,6 +269,7 @@ COMMANDS:
     build           Build project for running tests. This can be used to rebuild the project for changes.
     cert            Run a single thread-cert test. ENVIRONMENTS should be the same as those given to build or update.
     cert_suite      Run a batch of thread-cert tests and summarize the test results. Only echo logs for failing tests.
+    expect          Run expect tests.
     help            Print this help.
 
 EXAMPLES:
@@ -261,6 +292,12 @@ EXAMPLES:
     # Test Thread 1.2 with real time
     THREAD_VERSION=1.2 VIRTUAL_TIME=0 $0 clean build cert tests/scripts/thread-cert/v1_2_router_5_1_1.py
     THREAD_VERSION=1.2 VIRTUAL_TIME=0 $0 clean build cert_suite tests/scripts/thread-cert/v1_2_*
+
+    # Run a single expect test
+    $0 clean build expect tests/scripts/expect/log-level.exp
+
+    # Run all expect tests
+    $0 clean build expect
     "
 
     exit "$1"
@@ -350,6 +387,10 @@ main()
             package)
                 do_package
                 ;;
+            expect)
+                shift
+                do_expect "$@"
+                ;;
         esac
         shift
     done

src/cli/README.md

@@ -60,7 +60,7 @@ Done
 * [leaderpartitionid](#leaderpartitionid)
 * [leaderweight](#leaderweight)
 * [linkquality](#linkquality-extaddr)
-* [logfilename](#logfilename-filename)
+* [log](#log-filename-filename)
 * [mac](#mac-retries-direct)
 * [macfilter](#macfilter)
 * [masterkey](#masterkey)
@@ -889,7 +889,7 @@ Set the link quality on the link to a given extended address.
 Done
 ```
 
-### logfilename \<filename\>
+### log filename \<filename\>
 
 - Note: Simulation Only, ie: `OPENTHREAD_EXAMPLES_SIMULATION`
 - Requires `OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_DEBUG_UART`
@@ -898,6 +898,25 @@ Specifies filename to capture otPlatLog() messages, useful when
 debugging automated test scripts on Linux when logging disrupts
 the automated test scripts.
 
+### log level
+
+Get the log level.
+
+```bash
+> log level
+1
+Done
+```
+
+### log level \<level\>
+
+Set the log level.
+
+```bash
+> log level 4
+Done
+```
+
 ### masterkey
 
 Get the Thread Master Key value.

src/cli/cli.cpp

@@ -61,6 +61,7 @@
 
 #include <openthread/diag.h>
 #include <openthread/icmp6.h>
+#include <openthread/logging.h>
 #include <openthread/platform/uart.h>
 
 #include "common/new.hpp"
@@ -147,9 +148,7 @@ const struct Command Interpreter::sCommands[] = {
 #if OPENTHREAD_POSIX
     {"exit", &Interpreter::ProcessExit},
 #endif
-#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_DEBUG_UART) && OPENTHREAD_POSIX
-    {"logfilename", &Interpreter::ProcessLogFilename},
-#endif
+    {"log", &Interpreter::ProcessLog},
     {"extaddr", &Interpreter::ProcessExtAddress},
     {"extpanid", &Interpreter::ProcessExtPanId},
     {"factoryreset", &Interpreter::ProcessFactoryReset},
@@ -1363,20 +1362,47 @@ void Interpreter::ProcessExit(uint8_t aArgsLength, char *aArgs[])
 }
 #endif
 
-#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_DEBUG_UART) && OPENTHREAD_POSIX
-
-void Interpreter::ProcessLogFilename(uint8_t aArgsLength, char *aArgs[])
+void Interpreter::ProcessLog(uint8_t aArgsLength, char *aArgs[])
 {
     otError error = OT_ERROR_NONE;
 
-    VerifyOrExit(aArgsLength == 1, error = OT_ERROR_INVALID_ARGS);
+    VerifyOrExit(aArgsLength >= 1, error = OT_ERROR_INVALID_ARGS);
 
-    SuccessOrExit(error = otPlatDebugUart_logfile(aArgs[0]));
+    if (!strcmp(aArgs[0], "level"))
+    {
+        if (aArgsLength == 1)
+        {
+            mServer->OutputFormat("%d\r\n", otLoggingGetLevel());
+        }
+#if OPENTHREAD_CONFIG_LOG_LEVEL_DYNAMIC_ENABLE
+        else if (aArgsLength == 2)
+        {
+            long level;
+
+            SuccessOrExit(error = ParseLong(aArgs[1], level));
+            SuccessOrExit(error = otLoggingSetLevel(static_cast<otLogLevel>(level)));
+        }
+#endif
+        else
+        {
+            ExitNow(error = OT_ERROR_INVALID_ARGS);
+        }
+    }
+#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_DEBUG_UART) && OPENTHREAD_POSIX
+    else if (!strcmp(aArgs[0], "filename"))
+    {
+        VerifyOrExit(aArgsLength == 1, error = OT_ERROR_INVALID_ARGS);
+        SuccessOrExit(error = otPlatDebugUart_logfile(aArgs[1]));
+    }
+#endif
+    else
+    {
+        ExitNow(error = OT_ERROR_INVALID_ARGS);
+    }
 
 exit:
     AppendResult(error);
 }
-#endif
 
 void Interpreter::ProcessExtPanId(uint8_t aArgsLength, char *aArgs[])
 {

src/cli/cli.hpp

@@ -249,9 +249,7 @@ private:
 #if OPENTHREAD_POSIX
     void ProcessExit(uint8_t aArgsLength, char *aArgs[]);
 #endif
-#if (OPENTHREAD_CONFIG_LOG_OUTPUT == OPENTHREAD_CONFIG_LOG_OUTPUT_DEBUG_UART) && OPENTHREAD_POSIX
-    void ProcessLogFilename(uint8_t aArgsLength, char *aArgs[]);
-#endif
+    void    ProcessLog(uint8_t aArgsLength, char *aArgs[]);
     void    ProcessExtAddress(uint8_t aArgsLength, char *aArgs[]);
     void    ProcessExtPanId(uint8_t aArgsLength, char *aArgs[]);
     void    ProcessFactoryReset(uint8_t aArgsLength, char *aArgs[]);

src/core/api/logging_api.cpp

@@ -49,8 +49,19 @@ otLogLevel otLoggingGetLevel(void)
 }
 
 #if OPENTHREAD_CONFIG_LOG_LEVEL_DYNAMIC_ENABLE
-void otLoggingSetLevel(otLogLevel aLogLevel)
+otError otLoggingSetLevel(otLogLevel aLogLevel)
 {
-    Instance::Get().SetLogLevel(aLogLevel);
+    otError error = OT_ERROR_NONE;
+
+    if (aLogLevel <= OT_LOG_LEVEL_DEBG && aLogLevel >= OT_LOG_LEVEL_NONE)
+    {
+        Instance::Get().SetLogLevel(aLogLevel);
+    }
+    else
+    {
+        error = OT_ERROR_INVALID_ARGS;
+    }
+
+    return error;
 }
 #endif

src/core/common/instance.hpp

@@ -197,7 +197,11 @@ public:
      * @param[in] aLogLevel  A log level.
      *
      */
-    void SetLogLevel(otLogLevel aLogLevel) { mLogLevel = aLogLevel; }
+    void SetLogLevel(otLogLevel aLogLevel)
+    {
+        OT_ASSERT(aLogLevel <= OT_LOG_LEVEL_DEBG && aLogLevel >= OT_LOG_LEVEL_NONE);
+        mLogLevel = aLogLevel;
+    }
 #endif
 
     /**

tests/scripts/expect/log-level.exp

@@ -0,0 +1,45 @@
+#!/usr/bin/expect -f
+#
+#  Copyright (c) 2020, The OpenThread Authors.
+#  All rights reserved.
+#
+#  Redistribution and use in source and binary forms, with or without
+#  modification, are permitted provided that the following conditions are met:
+#  1. Redistributions of source code must retain the above copyright
+#     notice, this list of conditions and the following disclaimer.
+#  2. Redistributions in binary form must reproduce the above copyright
+#     notice, this list of conditions and the following disclaimer in the
+#     documentation and/or other materials provided with the distribution.
+#  3. Neither the name of the copyright holder nor the
+#     names of its contributors may be used to endorse or promote products
+#     derived from this software without specific prior written permission.
+#
+#  THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
+#  AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+#  IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
+#  ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE
+#  LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
+#  CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
+#  SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
+#  INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
+#  CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
+#  ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
+#  POSSIBILITY OF SUCH DAMAGE.
+#
+
+spawn $env(OT_COMMAND) 1
+set timeout 1
+expect_after {
+    timeout { exit 1 }
+}
+send "log level\n"
+expect "1\r\nDone\r\n"
+send "log level 5\n"
+expect "Done"
+send "log level\n"
+expect "5\r\nDone\r\n"
+send "log level -1\n"
+expect "Error 7: InvalidArgs\r\n"
+send "log level 6\n"
+expect "Error 7: InvalidArgs\r\n"
+send_user "\r\n"