[PATCH 0/4] selftests: ftrace: ftracetest improvements

[PATCH 0/4] selftests: ftrace: ftracetest improvements

[Masami Hiramatsu]

Hello,

Here is v2 of ftracetest improvements, including test
return code change and immediate logging features.

The first version is here.
https://patchwork.kernel.org/patch/9821943/
https://patchwork.kernel.org/patch/9821945/

This version adds 2 patches according discussions on
previous version. [2/4] adds --fail-unsupported option
which makes UNSUPPORTED result failure. [4/4] adds
"--logdir -" which logs all results in console but
no file.

Changes in v2:
 - [2/4]: (new) adds --fail-unsupported option
 - [3/4]: Fix not to show failure log twice
 - [4/4]: (new) adds --logdir "-" option so that
          all log goes to console directly.

Thank you,

---

Masami Hiramatsu (4):
      selftests: ftrace: Do not failure if there is unsupported tests
      selftests: ftrace: Add --fail-unsupported option
      selftests: ftrace: Add more verbosity for immediate log
      selftests: ftrace: Output only to console with "--logdir -"


 tools/testing/selftests/ftrace/ftracetest |   45 ++++++++++++++++++++++-------
 1 file changed, 34 insertions(+), 11 deletions(-)

--
Masami Hiramatsu (Linaro) <mhiramat@kernel.org>

[PATCH 1/4] selftests: ftrace: Do not failure if there is unsupported tests

[Masami Hiramatsu]

Do not return failure exit code (1) for unsupported testcases,
since it is expected for stable kernels.

Previously, ftracetest is expected to run only on current
release for avoiding regressions. However, nowadays we run
it on stable kernels. This means some test cases must return
unsupported result. In such case, we should NOT exit
ftracetest with error status for unsupported results so that
kselftest (upper tests wrapper) shows it passed correctly.

Note that we continue to treat unresolved results as failure,
if test writers would like to notice user that the test result
should be reviewed, they can use exit_unresolved.

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 tools/testing/selftests/ftrace/ftracetest |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest
index 14a03ea..290cd42 100755
--- a/tools/testing/selftests/ftrace/ftracetest
+++ b/tools/testing/selftests/ftrace/ftracetest
@@ -187,7 +187,7 @@ eval_result() { # sigval
     $UNSUPPORTED)
       prlog "	[UNSUPPORTED]"
       UNSUPPORTED_CASES="$UNSUPPORTED_CASES $CASENO"
-      return 1 # this is not a bug, but the result should be reported.
+      return 0 # this is not a bug.
     ;;
     $XFAIL)
       prlog "	[XFAIL]"

[PATCH 2/4] selftests: ftrace: Add --fail-unsupported option

[Masami Hiramatsu]

Add --fail-unsupported option to fail the test result if
ftracetest gets UNSUPPORTED result. UNSUPPORTED usually
happens when the kernel is old (e.g. stable tree) or some
kernel feature is disabled.

However, if newer kernel has any bug or regression, it
can make test results in UNSUPPORTED too. This option
can detect such kernel regression.

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 tools/testing/selftests/ftrace/ftracetest |    8 +++++++-
 1 file changed, 7 insertions(+), 1 deletion(-)

diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest
index 290cd42..e033f54 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 "		--fail-unsupported Treat UNSUPPORTED as a failure"
 echo "		-d|--debug Debug mode (trace all shell commands)"
 echo "		-l|--logdir <dir> Save logs on the <dir>"
 exit $1
@@ -65,6 +66,10 @@ parse_opts() { # opts
       DEBUG=1
       shift 1
     ;;
+    --fail-unsupported)
+      UNSUPPORTED_RESULT=1
+      shift 1
+    ;;
     --logdir|-l)
       LOG_DIR=$2
       shift 2
@@ -108,6 +113,7 @@ LOG_DIR=$TOP_DIR/logs/`date +%Y%m%d-%H%M%S`/
 KEEP_LOG=0
 DEBUG=0
 VERBOSE=0
+UNSUPPORTED_RESULT=0
 # Parse command-line options
 parse_opts $*
 
@@ -187,7 +193,7 @@ eval_result() { # sigval
     $UNSUPPORTED)
       prlog "	[UNSUPPORTED]"
       UNSUPPORTED_CASES="$UNSUPPORTED_CASES $CASENO"
-      return 0 # this is not a bug.
+      return $UNSUPPORTED_RESULT # depends on use case
     ;;
     $XFAIL)
       prlog "	[XFAIL]"

[PATCH 3/4] selftests: ftrace: Add more verbosity for immediate log

[Masami Hiramatsu]

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@kernel.org>
---
  Changes in v2:
    - Do not show failure log on console again.
---
 tools/testing/selftests/ftrace/ftracetest |   10 +++++++---
 1 file changed, 7 insertions(+), 3 deletions(-)

diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest
index e033f54..892ca4e 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 "		--fail-unsupported Treat UNSUPPORTED as a failure"
 echo "		-d|--debug Debug mode (trace all shell commands)"
 echo "		-l|--logdir <dir> Save logs on the <dir>"
@@ -57,9 +58,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)
@@ -258,7 +260,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
+  elif [ $VERBOSE -eq 2 ]; then
     __run_test $1 2>> $testlog | tee -a $testlog
   else
     __run_test $1 >> $testlog 2>&1
@@ -268,7 +272,7 @@ run_test() { # testfile
     # Remove test log if the test was done as it was expected.
     [ $KEEP_LOG -eq 0 ] && rm $testlog
   else
-    [ $VERBOSE -ge 1 ] && catlog $testlog
+    [ $VERBOSE -eq 1 -o $VERBOSE -eq 2 ] && catlog $testlog
     TOTAL_RESULT=1
   fi
   rm -rf $TMPDIR

[PATCH 4/4] selftests: ftrace: Output only to console with "--logdir -"

[Masami Hiramatsu]

Output logs only to console if "-" is given to --logdir
option. In this case, ftracetest doesn't record any log
on the disk, and all logs immediately shown (including
all command logs.) Since there is no "tee" in the middle
of command and console, it outputs the log really soon.

This option is useful only when the console is logged.

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 tools/testing/selftests/ftrace/ftracetest |   29 +++++++++++++++++++++--------
 1 file changed, 21 insertions(+), 8 deletions(-)

diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest
index 892ca4e..25792ee 100755
--- a/tools/testing/selftests/ftrace/ftracetest
+++ b/tools/testing/selftests/ftrace/ftracetest
@@ -19,6 +19,7 @@ echo "		-vvv       Alias of -v -v -v (Show all commands immediately)"
 echo "		--fail-unsupported Treat UNSUPPORTED as a failure"
 echo "		-d|--debug Debug mode (trace all shell commands)"
 echo "		-l|--logdir <dir> Save logs on the <dir>"
+echo "		            If <dir> is -, all logs output in console only"
 exit $1
 }
 
@@ -127,14 +128,20 @@ if [ -z "$TRACING_DIR" -o ! -d "$TRACING_DIR" ]; then
 fi
 
 # Preparing logs
-LOG_FILE=$LOG_DIR/ftracetest.log
-mkdir -p $LOG_DIR || errexit "Failed to make a log directory: $LOG_DIR"
-date > $LOG_FILE
+if [ "x$LOG_DIR" = "x-" ]; then
+  LOG_FILE=
+  date
+else
+  LOG_FILE=$LOG_DIR/ftracetest.log
+  mkdir -p $LOG_DIR || errexit "Failed to make a log directory: $LOG_DIR"
+  date > $LOG_FILE
+fi
+
 prlog() { # messages
-  echo "$@" | tee -a $LOG_FILE
+  [ -z "$LOG_FILE" ] && echo "$@" || echo "$@" | tee -a $LOG_FILE
 }
 catlog() { #file
-  cat $1 | tee -a $LOG_FILE
+  [ -z "$LOG_FILE" ] && cat $1 || cat $1 | tee -a $LOG_FILE
 }
 prlog "=== Ftrace unit tests ==="
 
@@ -255,12 +262,18 @@ __run_test() { # testfile
 # Run one test case
 run_test() { # testfile
   local testname=`basename $1`
-  local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
+  if [ "$LOG_FILE" ] ; then
+    local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
+  else
+    local testlog=`/proc/self/fd/1`
+  fi
   export TMPDIR=`mktemp -d /tmp/ftracetest-dir.XXXXXX`
   testcase $1
   echo "execute$INSTANCE: "$1 > $testlog
   SIG_RESULT=0
-  if [ $VERBOSE -ge 3 ]; then
+  if [ -z "$LOG_FILE" ]; then
+    __run_test $1 2>&1
+  elif [ $VERBOSE -ge 3 ]; then
     __run_test $1 | tee -a $testlog 2>&1
   elif [ $VERBOSE -eq 2 ]; then
     __run_test $1 2>> $testlog | tee -a $testlog
@@ -270,7 +283,7 @@ run_test() { # testfile
   eval_result $SIG_RESULT
   if [ $? -eq 0 ]; then
     # Remove test log if the test was done as it was expected.
-    [ $KEEP_LOG -eq 0 ] && rm $testlog
+    [ $KEEP_LOG -eq 0 -a "$LOG_FILE" ] && rm $testlog
   else
     [ $VERBOSE -eq 1 -o $VERBOSE -eq 2 ] && catlog $testlog
     TOTAL_RESULT=1

Re: [PATCH 4/4] selftests: ftrace: Output only to console with "--logdir -"

[Steven Rostedt]

On Tue,  4 Jul 2017 15:38:55 +0900
Masami Hiramatsu <mhiramat@kernel.org> wrote:

> Output logs only to console if "-" is given to --logdir
> option. In this case, ftracetest doesn't record any log
> on the disk, and all logs immediately shown (including
> all command logs.) Since there is no "tee" in the middle
> of command and console, it outputs the log really soon.
> 
> This option is useful only when the console is logged.
> 
> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> ---
>  tools/testing/selftests/ftrace/ftracetest |   29 +++++++++++++++++++++--------
>  1 file changed, 21 insertions(+), 8 deletions(-)
> 
> diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest
> index 892ca4e..25792ee 100755
> --- a/tools/testing/selftests/ftrace/ftracetest
> +++ b/tools/testing/selftests/ftrace/ftracetest
> @@ -19,6 +19,7 @@ echo "		-vvv       Alias of -v -v -v (Show all commands immediately)"
>  echo "		--fail-unsupported Treat UNSUPPORTED as a failure"
>  echo "		-d|--debug Debug mode (trace all shell commands)"
>  echo "		-l|--logdir <dir> Save logs on the <dir>"
> +echo "		            If <dir> is -, all logs output in console only"
>  exit $1
>  }
>  
> @@ -127,14 +128,20 @@ if [ -z "$TRACING_DIR" -o ! -d "$TRACING_DIR" ]; then
>  fi
>  
>  # Preparing logs
> -LOG_FILE=$LOG_DIR/ftracetest.log
> -mkdir -p $LOG_DIR || errexit "Failed to make a log directory: $LOG_DIR"
> -date > $LOG_FILE
> +if [ "x$LOG_DIR" = "x-" ]; then
> +  LOG_FILE=
> +  date
> +else
> +  LOG_FILE=$LOG_DIR/ftracetest.log
> +  mkdir -p $LOG_DIR || errexit "Failed to make a log directory: $LOG_DIR"
> +  date > $LOG_FILE
> +fi
> +
>  prlog() { # messages
> -  echo "$@" | tee -a $LOG_FILE
> +  [ -z "$LOG_FILE" ] && echo "$@" || echo "$@" | tee -a $LOG_FILE
>  }
>  catlog() { #file
> -  cat $1 | tee -a $LOG_FILE
> +  [ -z "$LOG_FILE" ] && cat $1 || cat $1 | tee -a $LOG_FILE
>  }
>  prlog "=== Ftrace unit tests ==="
>  
> @@ -255,12 +262,18 @@ __run_test() { # testfile
>  # Run one test case
>  run_test() { # testfile
>    local testname=`basename $1`
> -  local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
> +  if [ "$LOG_FILE" ] ; then

Shouldn't this be

	if [ ! -z "$LOG_FILE" ]; then

?

> +    local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
> +  else
> +    local testlog=`/proc/self/fd/1`

cute trick.

> +  fi
>    export TMPDIR=`mktemp -d /tmp/ftracetest-dir.XXXXXX`
>    testcase $1
>    echo "execute$INSTANCE: "$1 > $testlog
>    SIG_RESULT=0
> -  if [ $VERBOSE -ge 3 ]; then
> +  if [ -z "$LOG_FILE" ]; then
> +    __run_test $1 2>&1
> +  elif [ $VERBOSE -ge 3 ]; then
>      __run_test $1 | tee -a $testlog 2>&1
>    elif [ $VERBOSE -eq 2 ]; then
>      __run_test $1 2>> $testlog | tee -a $testlog
> @@ -270,7 +283,7 @@ run_test() { # testfile
>    eval_result $SIG_RESULT
>    if [ $? -eq 0 ]; then
>      # Remove test log if the test was done as it was expected.
> -    [ $KEEP_LOG -eq 0 ] && rm $testlog
> +    [ $KEEP_LOG -eq 0 -a "$LOG_FILE" ] && rm $testlog

again, don't we need to test "$LOG_FILE"?

-- Steve

>    else
>      [ $VERBOSE -eq 1 -o $VERBOSE -eq 2 ] && catlog $testlog
>      TOTAL_RESULT=1

Re: [PATCH 4/4] selftests: ftrace: Output only to console with "--logdir -"

[Steven Rostedt]

On Wed, 5 Jul 2017 12:25:06 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

 
> > @@ -255,12 +262,18 @@ __run_test() { # testfile
> >  # Run one test case
> >  run_test() { # testfile
> >    local testname=`basename $1`
> > -  local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
> > +  if [ "$LOG_FILE" ] ; then  
> 
> Shouldn't this be
> 
> 	if [ ! -z "$LOG_FILE" ]; then
> 
> ?
> 

OK, I just checked it out. I guess "" is considered zero and
"<anything>" is considered 1.

Hmm, do we do this in other places too. Just makes me unconfortable.

-- Steve

Re: [PATCH 4/4] selftests: ftrace: Output only to console with "--logdir -"

[Masami Hiramatsu]

On Wed, 5 Jul 2017 12:29:17 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Wed, 5 Jul 2017 12:25:06 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
>  
> > > @@ -255,12 +262,18 @@ __run_test() { # testfile
> > >  # Run one test case
> > >  run_test() { # testfile
> > >    local testname=`basename $1`
> > > -  local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
> > > +  if [ "$LOG_FILE" ] ; then  
> > 
> > Shouldn't this be
> > 
> > 	if [ ! -z "$LOG_FILE" ]; then
> > 
> > ?
> > 
> 
> OK, I just checked it out. I guess "" is considered zero and
> "<anything>" is considered 1.
> 
> Hmm, do we do this in other places too. Just makes me unconfortable.

OK, in that case, I can cleanup the code with [ ! -z "$VAR" ]

Thank you,

> 
> -- Steve
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH 4/4] selftests: ftrace: Output only to console with "--logdir -"

[Stafford Horne]

On Wed, Jul 05, 2017 at 12:25:06PM -0400, Steven Rostedt wrote:
> On Tue,  4 Jul 2017 15:38:55 +0900
> Masami Hiramatsu <mhiramat@kernel.org> wrote:
> 
> > +    local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
> > +  else
> > +    local testlog=`/proc/self/fd/1`
> 
> cute trick.

Shouldn't this be:

   local testlog=/proc/self/fd/1

without the backticks and subshell? We just want to write to the stdout
file not execute it.

Or am missing something.

-Stafford

Re: [PATCH 4/4] selftests: ftrace: Output only to console with "--logdir -"

[Steven Rostedt]

On Thu, 6 Jul 2017 22:06:58 +0900
Stafford Horne <shorne@gmail.com> wrote:

> On Wed, Jul 05, 2017 at 12:25:06PM -0400, Steven Rostedt wrote:
> > On Tue,  4 Jul 2017 15:38:55 +0900
> > Masami Hiramatsu <mhiramat@kernel.org> wrote:
> >   
> > > +    local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
> > > +  else
> > > +    local testlog=`/proc/self/fd/1`  
> > 
> > cute trick.  
> 
> Shouldn't this be:
> 
>    local testlog=/proc/self/fd/1
> 
> without the backticks and subshell? We just want to write to the stdout
> file not execute it.
> 
> Or am missing something.

Good eyes. I mistook those as quotes and not backticks.

-- Steve

Re: [PATCH 4/4] selftests: ftrace: Output only to console with "--logdir -"

[Masami Hiramatsu]

On Thu, 6 Jul 2017 22:06:58 +0900
Stafford Horne <shorne@gmail.com> wrote:

> On Wed, Jul 05, 2017 at 12:25:06PM -0400, Steven Rostedt wrote:
> > On Tue,  4 Jul 2017 15:38:55 +0900
> > Masami Hiramatsu <mhiramat@kernel.org> wrote:
> > 
> > > +    local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
> > > +  else
> > > +    local testlog=`/proc/self/fd/1`
> > 
> > cute trick.
> 
> Shouldn't this be:
> 
>    local testlog=/proc/self/fd/1
> 
> without the backticks and subshell? We just want to write to the stdout
> file not execute it.

Yeah, it was my mistake...

Thank you!

> 
> Or am missing something.
> 
> -Stafford


-- 
Masami Hiramatsu <mhiramat@kernel.org>