diff mbox series

[v1,22/23] tests/qemu-iotests: re-format output to for make check-block

Message ID 20190509165912.10512-23-alex.bennee@linaro.org
State Superseded
Headers show
Series current testing/next queue (docker/system & io tests) | expand

Commit Message

Alex Bennée May 9, 2019, 4:59 p.m. UTC
This attempts to clean-up the output to better match the output of the
rest of the QEMU check system. This includes:

  - formatting as "  TEST    iotest: nnn"
  - calculating time diff at the end
  - only dumping config on failure

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

Message-Id: <20190503143904.31211-1-alex.bennee@linaro.org>
---
 tests/qemu-iotests/check | 101 +++++++++++++++++++++++----------------
 1 file changed, 61 insertions(+), 40 deletions(-)

-- 
2.20.1

Comments

Max Reitz May 9, 2019, 6:12 p.m. UTC | #1
On 09.05.19 18:59, Alex Bennée wrote:
> This attempts to clean-up the output to better match the output of the

> rest of the QEMU check system. This includes:

> 

>   - formatting as "  TEST    iotest: nnn"

>   - calculating time diff at the end

>   - only dumping config on failure

> 

> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

> Message-Id: <20190503143904.31211-1-alex.bennee@linaro.org>

> ---

>  tests/qemu-iotests/check | 101 +++++++++++++++++++++++----------------

>  1 file changed, 61 insertions(+), 40 deletions(-)


Hm, this makes every iotest print two lines:

$ ./check -T -qcow2
[...]
001 [20:06:27] -> [20:06:27]
001 0s (last 1s)
002 [20:06:27] -> [20:06:28]
002 1s (last 1s)
003 [20:06:28] -> [20:06:29]
003 1s (last 1s)
004 [20:06:29] -> [20:06:29]
004 0s (last 0s)
005 [20:06:29] -> [20:06:29]
005 0s (last 0s)
[..]

Which looks rather weird to me.

Max
Alex Bennée May 9, 2019, 8:38 p.m. UTC | #2
Max Reitz <mreitz@redhat.com> writes:

> On 09.05.19 18:59, Alex Bennée wrote:

>> This attempts to clean-up the output to better match the output of the

>> rest of the QEMU check system. This includes:

>>

>>   - formatting as "  TEST    iotest: nnn"

>>   - calculating time diff at the end

>>   - only dumping config on failure

>>

>> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

>> Message-Id: <20190503143904.31211-1-alex.bennee@linaro.org>

>> ---

>>  tests/qemu-iotests/check | 101 +++++++++++++++++++++++----------------

>>  1 file changed, 61 insertions(+), 40 deletions(-)

>

> Hm, this makes every iotest print two lines:

>

> $ ./check -T -qcow2

> [...]

> 001 [20:06:27] -> [20:06:27]

> 001 0s (last 1s)


Yes - it was a compromise to ensure we printed a start and end
timestamp but I guess we can fix it up with a bit more shell ugliness:

--8<---------------cut here---------------start------------->8---

Subject: [PATCH] fixup! tests/qemu-iotests: re-format output to for make
 check-block

---
 tests/qemu-iotests/check | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

diff --git a/tests/qemu-iotests/check b/tests/qemu-iotests/check
index fb239967a32..9f083f06b46 100755
--- a/tests/qemu-iotests/check
+++ b/tests/qemu-iotests/check
@@ -726,7 +726,11 @@ _report_test_result()
     if $pretty; then
         echo "  TEST    iotest: $1 $2"
     else
-        echo "$1 $2"
+        if $timestamp; then
+            echo " $2"
+        else
+            echo "$1 $2"
+        fi
     fi
 }

@@ -793,7 +797,7 @@ do
                     $run_command >$tmp.out 2>&1)
         fi
         sts=$?
-        $timestamp && echo " [$(date "+%T")]"
+        $timestamp && echo -n " [$(date "+%T")]"
         stop=$(_wallclock)

         if [ -f core ]
--8<---------------cut here---------------end--------------->8---

--
Alex Bennée
Eric Blake May 9, 2019, 8:45 p.m. UTC | #3
On 5/9/19 3:38 PM, Alex Bennée wrote:

>> Hm, this makes every iotest print two lines:

>>

>> $ ./check -T -qcow2

>> [...]

>> 001 [20:06:27] -> [20:06:27]

>> 001 0s (last 1s)

> 

> Yes - it was a compromise to ensure we printed a start and end

> timestamp but I guess we can fix it up with a bit more shell ugliness:

> 

> --8<---------------cut here---------------start------------->8---

> 

> Subject: [PATCH] fixup! tests/qemu-iotests: re-format output to for make

>  check-block

> 

> ---

>  tests/qemu-iotests/check | 8 ++++++--

>  1 file changed, 6 insertions(+), 2 deletions(-)

> 

> diff --git a/tests/qemu-iotests/check b/tests/qemu-iotests/check

> index fb239967a32..9f083f06b46 100755

> --- a/tests/qemu-iotests/check

> +++ b/tests/qemu-iotests/check

> @@ -726,7 +726,11 @@ _report_test_result()

>      if $pretty; then

>          echo "  TEST    iotest: $1 $2"

>      else

> -        echo "$1 $2"

> +        if $timestamp; then

> +            echo " $2"

> +        else

> +            echo "$1 $2"

> +        fi


Why not just make $1 '' in the case where you've already printed a
timestamp, so that this code is still unconditionally echo "$1 $2"?

>      fi

>  }

> 

> @@ -793,7 +797,7 @@ do

>                      $run_command >$tmp.out 2>&1)

>          fi

>          sts=$?

> -        $timestamp && echo " [$(date "+%T")]"

> +        $timestamp && echo -n " [$(date "+%T")]"


'echo -n' is not portable (even in bash, since you can compile a
different default for shopt xpg_echo). Better is to use 'printf %s', as
is already done in _timestamp().

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3226
Virtualization:  qemu.org | libvirt.org
Thomas Huth May 10, 2019, 4:45 a.m. UTC | #4
On 09/05/2019 18.59, Alex Bennée wrote:
> This attempts to clean-up the output to better match the output of the

> rest of the QEMU check system. This includes:

> 

>   - formatting as "  TEST    iotest: nnn"

>   - calculating time diff at the end

>   - only dumping config on failure

> 

> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

> Message-Id: <20190503143904.31211-1-alex.bennee@linaro.org>

> ---

>  tests/qemu-iotests/check | 101 +++++++++++++++++++++++----------------

>  1 file changed, 61 insertions(+), 40 deletions(-)

[...]
> -cat <<EOF

> -QEMU          -- "$QEMU_PROG" $QEMU_OPTIONS

> -QEMU_IMG      -- "$QEMU_IMG_PROG" $QEMU_IMG_OPTIONS

> -QEMU_IO       -- "$QEMU_IO_PROG" $QEMU_IO_OPTIONS

> -QEMU_NBD      -- "$QEMU_NBD_PROG" $QEMU_NBD_OPTIONS

> -IMGFMT        -- $FULL_IMGFMT_DETAILS

> -IMGPROTO      -- $IMGPROTO

> -PLATFORM      -- $FULL_HOST_DETAILS

> -TEST_DIR      -- $TEST_DIR

> -SOCKET_SCM_HELPER -- $SOCKET_SCM_HELPER

> -

> -EOF

> +if ! $pretty; then

> +    _full_env_details

> +fi

>  

>  seq="check"

[...]
> @@ -852,9 +869,13 @@ do

>      #

>      if $err

>      then

> +        _report_test_result $seq "FAILED $reason"

> +        _full_env_details


I'd suggest to wrap the _full_env_details with a "if $pretty" statement,
otherwise the env will be printed out twice, one time at the beginning,
and one time in case of an error.

>          bad="$bad $seq"

>          n_bad=$(expr $n_bad + 1)

>          quick=false

> +    else

> +        _report_test_result $seq "$results"

>      fi

>      [ -f $seq.notrun ] || try=$(expr $try + 1)

>  

> 


 Thomas
diff mbox series

Patch

diff --git a/tests/qemu-iotests/check b/tests/qemu-iotests/check
index 922c5d1d3d3..fb239967a32 100755
--- a/tests/qemu-iotests/check
+++ b/tests/qemu-iotests/check
@@ -27,6 +27,7 @@  bad=""
 notrun=""
 casenotrun=""
 interrupt=true
+pretty=false
 
 # by default don't output timestamps
 timestamp=${TIMESTAMP:=false}
@@ -88,6 +89,22 @@  _full_platform_details()
     echo "$os/$platform $host $kernel"
 }
 
+_full_env_details()
+{
+    cat <<EOF
+QEMU          -- "$QEMU_PROG" $QEMU_OPTIONS
+QEMU_IMG      -- "$QEMU_IMG_PROG" $QEMU_IMG_OPTIONS
+QEMU_IO       -- "$QEMU_IO_PROG" $QEMU_IO_OPTIONS
+QEMU_NBD      -- "$QEMU_NBD_PROG" $QEMU_NBD_OPTIONS
+IMGFMT        -- $FULL_IMGFMT_DETAILS
+IMGPROTO      -- $IMGPROTO
+PLATFORM      -- $FULL_HOST_DETAILS
+TEST_DIR      -- $TEST_DIR
+SOCKET_SCM_HELPER -- $SOCKET_SCM_HELPER
+
+EOF
+}
+
 # $1 = prog to look for
 set_prog_path()
 {
@@ -256,6 +273,7 @@  other options
     -o options          -o options to pass to qemu-img create/convert
     -T                  output timestamps
     -c mode             cache mode
+    -pretty             pretty print output for make check
 
 testlist options
     -g group[,group...]        include tests from these groups
@@ -403,7 +421,10 @@  testlist options
                 command -v xxdiff >/dev/null 2>&1 && diff=xxdiff
             fi
             ;;
-
+        -pretty)   # pretty print output
+            pretty=true
+            xpand=false
+            ;;
         -n)        # show me, don't do it
             showme=true
             xpand=false
@@ -633,12 +654,6 @@  _wallclock()
     date "+%H %M %S" | awk '{ print $1*3600 + $2*60 + $3 }'
 }
 
-_timestamp()
-{
-    now=$(date "+%T")
-    printf %s " [$now]"
-}
-
 _wrapup()
 {
     if $showme
@@ -704,23 +719,25 @@  END        { if (NR > 0) {
 
 trap "_wrapup; exit \$status" 0 1 2 3 15
 
+# Report the test result, optionally pretty printing the result
+# args: sequence, results
+_report_test_result()
+{
+    if $pretty; then
+        echo "  TEST    iotest: $1 $2"
+    else
+        echo "$1 $2"
+    fi
+}
+
 [ -f $TIMESTAMP_FILE ] || touch $TIMESTAMP_FILE
 
 FULL_IMGFMT_DETAILS=$(_full_imgfmt_details)
 FULL_HOST_DETAILS=$(_full_platform_details)
 
-cat <<EOF
-QEMU          -- "$QEMU_PROG" $QEMU_OPTIONS
-QEMU_IMG      -- "$QEMU_IMG_PROG" $QEMU_IMG_OPTIONS
-QEMU_IO       -- "$QEMU_IO_PROG" $QEMU_IO_OPTIONS
-QEMU_NBD      -- "$QEMU_NBD_PROG" $QEMU_NBD_OPTIONS
-IMGFMT        -- $FULL_IMGFMT_DETAILS
-IMGPROTO      -- $IMGPROTO
-PLATFORM      -- $FULL_HOST_DETAILS
-TEST_DIR      -- $TEST_DIR
-SOCKET_SCM_HELPER -- $SOCKET_SCM_HELPER
-
-EOF
+if ! $pretty; then
+    _full_env_details
+fi
 
 seq="check"
 
@@ -728,8 +745,10 @@  seq="check"
 
 for seq in $list
 do
-    err=false
-    printf %s "$seq"
+    err=false     # error flag
+    reason=""     # reason for error
+    results=""    # results for non-error/skip
+
     if [ -n "$TESTS_REMAINING_LOG" ] ; then
         sed -e "s/$seq//" -e 's/  / /' -e 's/^ *//' $TESTS_REMAINING_LOG > $TESTS_REMAINING_LOG.tmp
         mv $TESTS_REMAINING_LOG.tmp $TESTS_REMAINING_LOG
@@ -738,7 +757,6 @@  do
 
     if $showme
     then
-        echo
         continue
     elif [ -f expunged ] && $expunge && egrep "^$seq([         ]|\$)" expunged >/dev/null
     then
@@ -753,17 +771,11 @@  do
         # really going to try and run this one
         #
         rm -f $seq.out.bad
-        lasttime=$(sed -n -e "/^$seq /s/.* //p" <$TIMESTAMP_FILE)
-        if [ "X$lasttime" != X ]; then
-                printf %s " ${lasttime}s ..."
-        else
-                printf "        "        # prettier output with timestamps.
-        fi
         rm -f core $seq.notrun
         rm -f $seq.casenotrun
 
         start=$(_wallclock)
-        $timestamp && printf %s "        [$(date "+%T")]"
+        $timestamp && echo -n "$seq [$(date "+%T")] ->"
 
         if [ "$(head -n 1 "$source_iotests/$seq")" == "#!/usr/bin/env python" ]; then
             run_command="$PYTHON $seq"
@@ -781,26 +793,24 @@  do
                     $run_command >$tmp.out 2>&1)
         fi
         sts=$?
-        $timestamp && _timestamp
+        $timestamp && echo " [$(date "+%T")]"
         stop=$(_wallclock)
 
         if [ -f core ]
         then
-            printf " [dumped core]"
             mv core $seq.core
+            reason="[dumped core] $seq.core"
             err=true
         fi
 
         if [ -f $seq.notrun ]
         then
-            $timestamp || printf " [not run] "
-            $timestamp && echo " [not run]" && printf %s "        $seq -- "
-            cat $seq.notrun
-            notrun="$notrun $seq"
+            # overwrites timestamp output
+            results="[not run] $(cat $seq.notrun)"
         else
             if [ $sts -ne 0 ]
             then
-                printf %s " [failed, exit status $sts]"
+                reason=$(printf %s "[failed, exit status $sts]")
                 err=true
             fi
 
@@ -821,22 +831,29 @@  do
 
             if [ ! -f "$reference" ]
             then
-                echo " - no qualified output"
+                reason=" - no qualified output"
                 err=true
             else
                 if diff -w "$reference" $tmp.out >/dev/null 2>&1
                 then
-                    echo ""
                     if $err
                     then
                         :
                     else
-                        echo "$seq $(expr $stop - $start)" >>$tmp.time
+                        lasttime=$(sed -n -e "/^$seq /s/.* //p" <$TIMESTAMP_FILE)
+                        thistime=$(expr $stop - $start)
+                        echo "$seq $thistime" >>$tmp.time
+
+                        if [ "X$lasttime" != X ]; then
+                            results="${results}${thistime}s (last ${lasttime}s)"
+                        else
+                            results="${results}${thistime}s"
+                        fi
                     fi
                 else
-                    echo " - output mismatch (see $seq.out.bad)"
                     mv $tmp.out $seq.out.bad
                     $diff -w "$reference" "$PWD"/$seq.out.bad
+                    reason=" - output mismatch (see $seq.out.bad)"
                     err=true
                 fi
             fi
@@ -852,9 +869,13 @@  do
     #
     if $err
     then
+        _report_test_result $seq "FAILED $reason"
+        _full_env_details
         bad="$bad $seq"
         n_bad=$(expr $n_bad + 1)
         quick=false
+    else
+        _report_test_result $seq "$results"
     fi
     [ -f $seq.notrun ] || try=$(expr $try + 1)