Re: [PATCH 2/2] selftests: ftrace: Add more verbosity for immediate log

[Steven Rostedt]

On Mon,  3 Jul 2017 14:26:40 +0900
Masami Hiramatsu <mhiramat@xxxxxxxxxx> wrote:

> Add 3-level verbosity for showing traced command log
> on console immediately. Since some test cases can cause
> kernel pacic if there is a probrem (like regression etc.),
> we can not know which command caused the problem without
> traced command log. This verbosity (-vvv) solves that
> because it shows the log on console immediately. User
> can get continuous command/error log.
> 
> Note that this is a kind of kernel debug mode, if you
> don't see any kernel related issue, you don't need this
> verbosity.
> 
> Signed-off-by: Masami Hiramatsu <mhiramat@xxxxxxxxxx>
> ---
>  tools/testing/selftests/ftrace/ftracetest |    8 ++++++--
>  1 file changed, 6 insertions(+), 2 deletions(-)
> 
> diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest
> index 290cd42..e3f1521 100755
> --- a/tools/testing/selftests/ftrace/ftracetest
> +++ b/tools/testing/selftests/ftrace/ftracetest
> @@ -15,6 +15,7 @@ echo "		-h|--help  Show help message"
>  echo "		-k|--keep  Keep passed test logs"
>  echo "		-v|--verbose Increase verbosity of test messages"
>  echo "		-vv        Alias of -v -v (Show all results in stdout)"
> +echo "		-vvv       Alias of -v -v -v (Show all commands immediately)"
>  echo "		-d|--debug Debug mode (trace all shell commands)"
>  echo "		-l|--logdir <dir> Save logs on the <dir>"
>  exit $1
> @@ -56,9 +57,10 @@ parse_opts() { # opts
>        KEEP_LOG=1
>        shift 1
>      ;;
> -    --verbose|-v|-vv)
> +    --verbose|-v|-vv|-vvv)
>        VERBOSE=$((VERBOSE + 1))
>        [ $1 = '-vv' ] && VERBOSE=$((VERBOSE + 1))
> +      [ $1 = '-vvv' ] && VERBOSE=$((VERBOSE + 2))
>        shift 1
>      ;;
>      --debug|-d)
> @@ -252,7 +254,9 @@ run_test() { # testfile
>    testcase $1
>    echo "execute$INSTANCE: "$1 > $testlog
>    SIG_RESULT=0
> -  if [ $VERBOSE -ge 2 ]; then
> +  if [ $VERBOSE -ge 3 ]; then
> +    __run_test $1 | tee -a $testlog 2>&1

I have nothing against this patch, but I want to point out that the
above is far from printing everything out immediately. The tee command
buffers a bit. At least it has for me in the past. If the kernel does
crash, one needs to still be a bit weary of where exactly the crash
happened.

Perhaps we need an option to print not to a log, but just let the test
print out directly?

-- Steve



> +  elif [ $VERBOSE -eq 2 ]; then
>      __run_test $1 2>> $testlog | tee -a $testlog
>    else
>      __run_test $1 >> $testlog 2>&1